lpr notifications thru postfix
I have postfix installed and configured on my Mac OS 10.6.3 machines. It works correctly because the unix mail program works fine and sendmail interface can send emails as well. However, I encounter this strange problem. The printing commands, lpr and lp, have the -m switch which sends an e-mail on completion of a print job. This email is not delivered and in /var/log/mail.log I see the following error: May 7 00:00:04 MacBookPro postfix/sendmail[6309]: fatal: execvp /usr/sbin/postdrop: Operation not permitted May 7 00:00:05 MacBookPro postfix/sendmail[6308]: warning: command "/usr/sbin/postdrop -r" exited with status 1 May 7 00:00:05 MacBookPro postfix/sendmail[6308]: fatal: _lp(26): unable to execute /usr/sbin/postdrop -r: Unknown error: 0 Can someone give me a clue as to what is wrong? Funny thing is that sometimes it starts working on its own and then stops again. Jamal
Re: lpr notifications thru postfix
On May 9, 2010, at 12:18 PM, Reinaldo de Carvalho wrote: > On Sat, May 8, 2010 at 7:51 PM, Jamal Mubarak wrote: >> I have postfix installed and configured on my Mac OS 10.6.3 machines. It >> works correctly because the unix mail program works fine and sendmail >> interface can send emails as well. However, I encounter this strange >> problem. The printing commands, lpr and lp, have the -m switch which sends >> an e-mail on completion of a print job. This email is not delivered and in >> /var/log/mail.log I see the following error: >> >> May 7 00:00:04 MacBookPro postfix/sendmail[6309]: fatal: execvp >> /usr/sbin/postdrop: Operation not permitted >> May 7 00:00:05 MacBookPro postfix/sendmail[6308]: warning: command >> "/usr/sbin/postdrop -r" exited with status 1 >> May 7 00:00:05 MacBookPro postfix/sendmail[6308]: fatal: _lp(26): unable to >> execute /usr/sbin/postdrop -r: Unknown error: 0 >> >> Can someone give me a clue as to what is wrong? Funny thing is that >> sometimes it starts working on its own and then stops again. > > Show permissions of /usr/sbin/postdrop and /usr/sbin/sendmail. lpr/lp > process owner have rights to exec this commands? Here are my permissions: -rwxr-sr-x 1 root _postdrop 484912 Feb 11 01:03 /usr/sbin/postdrop -rwxr-xr-x 1 root wheel 572512 Feb 11 01:03 /usr/sbin/sendmail -r-xr-xr-x 1 root wheel 52832 Feb 11 01:47 lp -r-xr-xr-x 1 root wheel 44304 Feb 11 01:47 lpoptions -r-xr-xr-x 1 root wheel 44400 Feb 11 01:47 lppasswd -r-xr-xr-x 1 root wheel 44528 Feb 11 01:47 lpq -r-xr-xr-x 1 root wheel 44304 Feb 11 01:47 lpr -r-xr-xr-x 1 root wheel 35040 Feb 11 01:47 lprm -r-xr-xr-x 1 root wheel 73552 Feb 11 01:47 lpstat On May 9, 2010, at 7:56 AM, Wietse Venema wrote: > Ask Apple. Postfix does not change spontaneously. I filed a bug report with Apple with number 7477314. They asked me for some details about my system, including permissions. Then nothing. I have tried to post to a few forums, including the CUPS forum, but no luck. Can someone offer me some ideas on how to attack this problem? Jamal
Re: lpr notifications thru postfix
On May 9, 2010, at 5:56 PM, Wietse Venema wrote:
> This involves getting a trace of system calls (arguments and results)
> when the error happens.
>
> Some systems capture a system call trace with commands like:
>
>ktrace -f /file/name -d command
>strace -o /file/name -f command
>truss -o /file/name -f command
>
> But, things may be different on MacOS.
>
> Above, "command" is the command that starts the entire printing
> system. On some systems, "command" would be:
>
>sh /etc/rc.d/cups start
>sh /etc/init.d/cups start
Thanks for replying! I did try "dtruss -n sendmail". It gave me a large
output which I compared with a regular email that did not fail. It is hard for
me to decipher but here is a part of it. The rest is given below:
11901/0x3ecda: fstat64(0x3, 0x7FFF5FBFF650, 0xFC080)= 0 0
11901/0x3ecda: close(0x3) = 0 0
11901/0x3ecda: getrlimit(0x1008, 0x7FFF5FBFEE10, 0x7FFF82755CCC)
= 0 0
11901/0x3ecda: open_nocancel("/etc/sysinfo.conf\0", 0x0, 0x1B6)
= -1 Err#2
11901/0x3ecda: fork() = 11902 0
11902/0x3ecdc: __semwait_signal(0x803, 0x0, 0x1)= -1 Err#60
11901/0x3ecda: read(0x4, "\333\006\0", 0x1000) = 0 0
11901/0x3ecda: close(0x4) = 0 0
11901/0x3ecda: wait4(0x2E7E, 0x7FFF5FBFF73C, 0x0) = 11902 0
11901/0x3ecda: write(0x2, "sendmail: warning: command \"/usr/sbin/postdrop
-r\" exited with status 1\n\0", 0x48)= 72 0
11901/0x3ecda: gettimeofday(0x7FFF5FBFF3C0, 0x0, 0x10) = 1273446059 0
11901/0x3ecda: getuid(0x0, 0x7FFF704A25F0, 0x7FFF704A25F0) = 26 0
11901/0x3ecda: getgid(0x0, 0x7FFF704A25F0, 0x7FFF704A25F0) = 26 0
11901/0x3ecda: __sysctl(0x7FFF5FBFF220, 0x2, 0x7FFF5FBFF230)= 0 0
11901/0x3ecda: write(0x2, "sendmail: fatal: _lp(26): unable to execute
/usr/sbin/postdrop -r: Unknown error: 0\n\0", 0x54) = 84 0
11901/0x3ecda: getuid(0x0, 0x7FFF704A25F0, 0x7FFF704A25F0) = 26 0
11901/0x3ecda: getgid(0x0, 0x7FFF704A25F0, 0x7FFF704A25F0) = 26 0
11901/0x3ecda: __sysctl(0x7FFF5FBFF240, 0x2, 0x7FFF5FBFF250)= 0 0
I am frankly unable to understand this. Note that _lp has the user id of 26.
Should I do it for cups or the CUPS notifier? Any help would be appreciated.
Thanks,
Jamal
--Full output--
PID/THRD SYSCALL(args) = return
11901/0x3ecda: getpid(0x7FFF5FBFF7C0, 0x7FE00050, 0x0) =
11901 0
11901/0x3ecda: open_nocancel("/dev/urandom\0", 0x0, 0x0)= 3 0
11901/0x3ecda: read_nocancel(0x3,
"\277C\270\214\326L\221\361\322.\264_iN\270\266D\335't\313\032\fu\3259\232x\027\250!\030}\336\200z\315h\324\004\016\273\272\031\210!b\347\...@\220<\265\207\001/\t\316+\201\352\274\204\232\"\023|\260l\036\362\322\276\207\231\267\254\350\373\221\234\371\342\237e&\262\336\213S\004\330\377\232\023\260E\2600\325\265\035#\221\300\277\"\372\0",
0x6C) = 108 0
11901/0x3ecda: close_nocancel(0x3) = 0 0
11901/0x3ecda: issetugid(0x1, 0x7FFF5FBFFA92, 0x7FFF5FC40530)
= 0 0
11901/0x3ecda: geteuid(0x1, 0x7FFF5FBFFA92, 0x0)= 26 0
11901/0x3ecda: __sysctl(0x7FFF5FBFD6B0, 0x2, 0x7FFF5FBFD670)= 0 0
11901/0x3ecda: __sysctl(0x7FFF5FBFD670, 0x2, 0x7FFF5FBFD70C)= 0 0
11901/0x3ecda: shared_region_check_np(0x7FFF5FBFD878, 0x0, 0x7FFF5FC1DC86)
= 0 0
11901/0x3ecda:
stat64("/System/Library/Frameworks/OpenDirectory.framework/Versions/A/OpenDirectory\0",
0x7FFF5FBFC9C0, 0x7FFF5FBFD000) = 0 0
11901/0x3ecda: stat64("/usr/lib/libssl.0.9.8.dylib\0", 0x7FFF5FBFC9C0,
0x7FFF5FBFD000) = 0 0
11901/0x3ecda: stat64("/usr/lib/libsasl2.2.dylib\0", 0x7FFF5FBFC9C0,
0x7FFF5FBFD000)= 0 0
11901/0x3ecda:
stat64("/System/Library/Frameworks/Kerberos.framework/Versions/A/Kerberos\0",
0x7FFF5FBFC9C0, 0x7FFF5FBFD000)= 0 0
11901/0x3ecda: stat64("/usr/lib/libpcre.0.dylib\0", 0x7FFF5FBFC9C0,
0x7FFF5FBFD000) = 0 0
11901/0x3ecda: ioctl(0x3, 0x80086804, 0x7FFF5FBFD610) = 0 0
11901/0x3ecda: __sysctl(0x7FFF5FBFD410, 0x2, 0x7FFF5FBFD400)= 0 0
11901/0x3ecda: bsdthread_register(0x7FFF8278B75C, 0x7FFF8276C378, 0x2000)
= 0 0
11901/0x3ecda: thread_selfid(0x7FFF8278B75C, 0x7FFF8276C378, 0x0)
= 257242 0
11901/0x3ecda: open_nocancel("/dev/urandom\0", 0x0, 0x7FFF704ABB20)
= 3 0
11901/0x3ecda: read_nocancel(0x3,
"\223\242\030\214\037\346\270'\241\233n\v=2\242\223p\360\253GQ\330f/\327`f\324\264\266\002\341l\357\305k\t\001\t\346\355\004\331od\350\362h\202\320\...@\265d\334\024\275\363\314\237\204\262\237\335\0",
0x40) = 64 0
11901/0x3ecda: close_nocancel(0x3) = 0 0
11901/0x3ecda: mmap(0x0, 0x3000, 0x3, 0x1002, 0x100, 0x7FFF0001)
Re: lpr notifications thru postfix
On May 9, 2010, at 6:46 PM, Wietse Venema wrote:
> The problem does not happen in the Sendmail process that you run,
> but in a CHILD process of that Sendmail process.
>
> Therefore, you need to specify an option to trace CHILD processes.
>
> The examples above use "-d" or "-f" to achieve that. MacOS dtrace
> may have a different option for the same purpose.
You are the first person to truly help me! Yes, indeed, the -f option traces
child processes. Here is the end of the output for the command "sudo dtruss
-fn sendmail":
12180/0x403cc: fstat64(0x3, 0x7FFF5FBFF650, 0xFC080)= 0 0
12180/0x403cc: close(0x3) = 0 0
12180/0x403cc: getrlimit(0x1008, 0x7FFF5FBFEE10, 0x7FFF82755CCC)
= 0 0
12180/0x403cc: open_nocancel("/etc/sysinfo.conf\0", 0x0, 0x1B6)
= -1 Err#2
12180/0x403cc: __sysctl(0x7FFF5FBFF440, 0x6, 0x0) = 0 0
12180/0x403cc: __sysctl(0x7FFF5FBFF440, 0x6, 0x10082C000) = 0 0
12180/0x403cc: geteuid(0x10001C78E, 0x7FE00050, 0x0)= 26 0
12180/0x403cc: getuid(0x10001C78E, 0x7FE00050, 0x0) = 26 0
12180/0x403cc: getgid(0x10001C78E, 0x7FE00050, 0x1) = 26 0
12180/0x403cc: getegid(0x10001C78E, 0x7FE00050, 0x0)= 26 0
12180/0x403cc: mmap(0x0, 0x3000, 0x3, 0x1002, 0x100, 0x1)
= 0x81000 0
12180/0x403cc: __sysctl(0x7FFF5FBFF640, 0x2, 0x7FFF5FBFF600)= 0 0
12180/0x403cc: __sysctl(0x7FFF5FBFF600, 0x2, 0x7FFF5FBFF698)= 0 0
12180/0x403cc: __sysctl(0x7FFF5FBFF640, 0x2, 0x7FFF5FBFF66C)= 0 0
12180/0x403cc: mmap(0x0, 0xD000, 0x3, 0x1002, 0x100, 0x1)
= 0x84000 0
12180/0x403cc: mmap(0x0, 0xD000, 0x3, 0x1002, 0x100, 0x1)
= 0x91000 0
12180/0x403cc: mmap(0x0, 0x20, 0x3, 0x1002, 0x700, 0x1)
= 0x20 0
12180/0x403cc: munmap(0x10030, 0x10)= 0 0
12180/0x403cc: chdir("/private/var/spool/postfix\0", 0x10010F36E, 0x0)
= 0 0
12180/0x403cc: sigaction(0xD, 0x7FFF5FBFF740, 0x7FFF5FBFF770) = 0 0
12180/0x403cc: getuid(0x2, 0x1, 0x1)= 26 0
12180/0x403cc: getuid(0x100111714, 0x, 0x0) = 26 0
12180/0x403cc: socketpair(0x1, 0x1, 0x0)= 0 0
12180/0x403cc: fork() = 12181 0
12180/0x403cc: close(0x3) = 0 0
12181/0x403d0: fork() = 0 0
12181/0x403d0: thread_selfid(0x7FFF704AEBE0, 0x3, 0x1) = 263120 0
12181/0x403d0: getpid(0x7FFF704AEBE0, 0x3, 0x0) = 12181 0
12181/0x403d0: close(0x4) = 0 0
12181/0x403d0: dup2(0x3, 0x0, 0x0) = 0 0
12181/0x403d0: dup2(0x3, 0x1, 0x0) = 1 0
12181/0x403d0: close(0x3) = 0 0
12181/0x403d0: geteuid(0x1001121B0, 0x3D, 0x3D) = 26 0
12181/0x403d0: getuid(0x1001121B0, 0x3D, 0x0) = 26 0
12181/0x403d0: getgid(0x1001121B0, 0x3D, 0x1) = 26 0
12181/0x403d0: getegid(0x1001121B0, 0x3D, 0x0) = 26 0
12181/0x403d0: geteuid(0x100112210, 0x3D, 0x3D) = 26 0
12181/0x403d0: getuid(0x100112210, 0x3D, 0x0) = 26 0
12181/0x403d0: getgid(0x100112210, 0x3D, 0x1) = 26 0
12181/0x403d0: getegid(0x100112210, 0x3D, 0x0) = 26 0
12181/0x403d0: geteuid(0x100112230, 0x3D, 0x3D) = 26 0
12181/0x403d0: getuid(0x100112230, 0x3D, 0x0) = 26 0
12181/0x403d0: getgid(0x100112230, 0x3D, 0x1) = 26 0
12181/0x403d0: getegid(0x100112230, 0x3D, 0x0) = 26 0
12181/0x403d0: execve(0x100112280, 0x100112380, 0x100200010)= -1
Err#1
12181/0x403d0: stat64("/usr/sbin/postdrop\0", 0x7FFF5FBFF100, 0x2)
= 0 0
12181/0x403d0: write(0x2, "sendmail: fatal: execvp /usr/sbin/postdrop:
Operation not permitted\n\0", 0x44) = 68 0
12181/0x403d0: geteuid(0x7FFF704A4180, 0x0, 0xB)= 26 0
12181/0x403d0: getuid(0x0, 0x7FFF704A25F0, 0x7FFF704A25F0) = 26 0
12181/0x403d0: getgid(0x0, 0x7FFF704A25F0, 0x7FFF704A25F0) = 26 0
12181/0x403d0: __sysctl(0x7FFF5FBFF0A0, 0x2, 0x7FFF5FBFF0B0)= 0 0
12180/0x403cc: getuid(0x0, 0x7FFF704A25F0, 0x7FFF704A25F0) = 26 0
12180/0x403cc: getgid(0x0, 0x7FFF704A25F0, 0x7FFF704A25F0) = 26 0
12180/0x403cc: __sysctl(0x7FFF5FBFF220, 0x2, 0x7FFF5FBFF230)= 0 0
12180/0x403cc: write(0x2, "sendmail: fatal: _lp(26): unable to execute
/usr/sbin/postdrop -r: Unknown error: 0\n\0", 0x54) = 84 0
12180/0x403cc: getuid(0x0, 0x7FFF704A25F0, 0x7FFF704A25F0) = 26 0
12180/0x403cc: getgid(0x0, 0x7FFF704A25F0, 0x7FFF704A25F0) = 26 0
12180/0x403cc: __sysctl(0x7FFF5FBFF240, 0x2, 0x7FFF5FBFF250)= 0 0
12181/0x403d0: __semwait_signal(0x803, 0x0, 0x1)= -1 Err#60
12180/0x403cc: read(0x4, "\333\006\0", 0x1000) = 0 0
1
Re: lpr notifications thru postfix
On May 9, 2010, at 7:35 PM, Wietse Venema wrote: > execve() fails with error number 1. You can look that number up in > /usr/include/sys/errno.h (or whatever the pathname is on MacOS). > But, MacOS is a descendant of FreeBSD, and on my machine: > > #define EPERM 1 /* Operation not permitted */ You are absolutely correct. > Now the question is why execve() fails with EPERM. > > On UNIX systems, EPERM does not report a file permission problem. > Instead: > > 1 EPERM Operation not permitted. An attempt was made to perform an oper- > ation limited to processes with appropriate privileges or to the > owner of a file or other resources. > > For example, only the owner (or root) can change the owner or > permissions of a file; everyone gets an EPERM error. The same error > is returned when a non-root process attempts to raise some resource > limit beyond its hard limit. > > Unfortunately, I see no EPERM error in the FreeBSD exec.c library > module or in the kern_exec.c kernel side. Perhaps MacOS has "extra > security" features similar to Systrace or AppArmor that interfere > with Postfix operation, or you are using a weird file system that > burps errors. So if I can find out what this security policy is, and disable it, the print confirmation emails will go thru? Thank you once again for looking into my problem. Jamal
Re: lpr notifications thru postfix
On May 9, 2010, at 8:31 PM, Reinaldo de Carvalho wrote: > On Sun, May 9, 2010 at 7:19 PM, Jamal Mubarak wrote: >> >> >> Show permissions of /usr/sbin/postdrop and /usr/sbin/sendmail. lpr/lp >> process owner have rights to exec this commands? >> >> Here are my permissions: >> >> -rwxr-sr-x 1 root _postdrop 484912 Feb 11 01:03 /usr/sbin/postdrop >> -rwxr-xr-x 1 root wheel 572512 Feb 11 01:03 /usr/sbin/sendmail >> -r-xr-xr-x 1 root wheel 52832 Feb 11 01:47 lp >> -r-xr-xr-x 1 root wheel 44304 Feb 11 01:47 lpoptions >> -r-xr-xr-x 1 root wheel 44400 Feb 11 01:47 lppasswd >> -r-xr-xr-x 1 root wheel 44528 Feb 11 01:47 lpq >> -r-xr-xr-x 1 root wheel 44304 Feb 11 01:47 lpr >> -r-xr-xr-x 1 root wheel 35040 Feb 11 01:47 lprm >> -r-xr-xr-x 1 root wheel 73552 Feb 11 01:47 lpstat >> On May 9, 2010, at 7:56 AM, Wietse Venema wrote: >> > > cups owner process is in the group _postdrop? > > 'owner process' isn't 'owner of lp* files', you need look owner pf > cups process with 'ps' command. jamal% ps -afx | grep cups 0 11783 1 0 0:00.90 ?? 0:00.96 /usr/sbin/cupsd -l jamal% ls -l /usr/sbin/cupsd -r-x-- 1 root wheel 887456 Feb 11 01:47 /usr/sbin/cupsd Is this what you are asking for? I have tried to change the group of /usr/sbin/postdrop to "wheel" from "_postdrop" without any difference. Same error. Jamal
Re: lpr notifications thru postfix
On May 10, 2010, at 8:25 AM, Reinaldo de Carvalho wrote: > On Sun, May 9, 2010 at 11:24 PM, Jamal Mubarak wrote: >>> >>> 'owner process' isn't 'owner of lp* files', you need look owner pf >>> cups process with 'ps' command. >> >> jamal% ps -afx | grep cups >>0 11783 1 0 0:00.90 ?? 0:00.96 /usr/sbin/cupsd -l > > Who is the process onwer? try 'ps -ef | grep cups' ps -aux does not work in Mac OS (Darwin) any more. jamal% ps -ajx | grep cups root 11783 1 11783 8fade780 Ss ??0:01.71 /usr/sbin/cupsd -l So it appears that cups is running as root. >> jamal% ls -l /usr/sbin/cupsd >> -r-x-- 1 root wheel 887456 Feb 11 01:47 /usr/sbin/cupsd >> >> Is this what you are asking for? I have tried to change the group of >> /usr/sbin/postdrop to "wheel" from "_postdrop" without any difference. Same >> error. > > Cups process onwer is in wheel? I think no. Apparently so, but I defer to your wisdom. On May 10, 2010, at 5:57 PM, mouss wrote: > OP has "another" problem. see Wietse posts. Well, Mac OS has BSM (Basic Security Module) audit. http://www.trustedbsd.org/openbsm.html http://developer.apple.com/mac/library/DOCUMENTATION/Darwin/Reference/ManPages/man2/auditon.2.html Should I mess with auditon? Jamal
