My original post is below. Here is some more detail on this issue. When
running Amavisd-New 2.0 and SA 2.63, Pyzor, Razor, and DCC all run fine.
However, after upgrading to SA 3.0-pre3, Pyzor times out on all queries, but
Razor and DDC still run fine:
Amavisd-New 2.0 & SA 2.63:
==========
debug: Razor2 is available
debug: Pyzor is available: /usr/local/bin/pyzor
debug: entering helper-app run mode
debug: Pyzor: got response: 66.250.40.33:24441 (200, 'OK') 0 0
debug: leaving helper-app run mode
debug: DCCifd is available: /var/dcc/dccifd
debug: entering helper-app run mode
debug: DCCifd: got response: X-DCC-dmv.com-Metrics: gw2.pointshare.com 1181;
Body=1 Fuz1=1 Fuz2=1
debug: leaving helper-app run mode
==========
Amavisd-New 2.0 & SA 3.0-pre3:
==========
debug: Razor2 is available
debug: Pyzor is available: /usr/local/bin/pyzor
debug: entering helper-app run mode
debug: setuid: helper proc 9392: ruid=3000 euid=3000
debug: leaving helper-app run mode
debug: Pyzor -> check timed out after 10 secs.
debug: DCCifd is available: /var/dcc/dccifd
debug: entering helper-app run mode
debug: DCCifd: got response: X-DCC-sonic.net-Metrics: mgw1.pointshare.com
1117; Body=1 Fuz1=1 Fuz2=1
debug: leaving helper-app run mode
==========
It appears that the only difference between SA 2.63 and SA 3.0-pre3 is the
addition of the "setuid" line:
debug: setuid: helper proc 9392: ruid=3000 euid=3000
UID 3000 & GID 3000 are owned by Amavisd-New. Was this "setuid" process an
intentional change, as it would seem to restrict Amavisd-New's ability to
access the Python/Pyzor applications as they are owned by root. I have
attached an strace snippet that shows that with SA 3.0-pre3, when attempting
to call Python and Pyzor, the process experiences lots of "Bad file
descriptor" issues, which are not present with SA 2.63.
Hopefully one of the devs will respond with some feedback on this. Should I
log this as a bug, or is there a workaround for this issue that I'm not
seeing.
Regards,
Bill
PS, wanted to thank William Stearns for the nice "apptrace" tool (available
at www.stearns.org), it helped a lot to be able to capture what was
happening with this issue.
----- Original Message -----
From: "Bill Landry" <[EMAIL PROTECTED]>
To: <[EMAIL PROTECTED]>;
<[EMAIL PROTECTED]>
Sent: Friday, July 23, 2004 3:16 PM
Subject: Pyzor issue with Amavisd-New 2.0 & SA 3.0.0-pre3
> I am using amavisd-new 2.0 to call spamassassin and when I start amavisd
in
> debug-sa mode, all helper-apps test fine, including pyzor:
> ==========
> debug: Pyzor is available: /usr/bin/pyzor
> debug: entering helper-app run mode
> debug: setuid: helper proc 20615: ruid=3000 euid=3000
> debug: Pyzor: got response: 66.250.40.33:24441 (200, 'OK') 0 0
> debug: leaving helper-app run mode
> ==========
>
> And when piping a test message into SA, all is fine, as well:
> spamassassin -dtD < test.msg
> ==========
> debug: Pyzor is available: /usr/bin/pyzor
> debug: entering helper-app run mode
> debug: setuid: helper proc 2513: ruid=0 euid=0
> debug: Pyzor: got response: 66.250.40.33:24441 (200, 'OK') 47 0
> debug: leaving helper-app run mode
> ==========
>
> However, once amavisd-new has fully started and mail is received, pyzor
> times out on every message:
> ==========
> debug: Pyzor is available: /usr/bin/pyzor
> debug: entering helper-app run mode
> debug: setuid: helper proc 2602: ruid=3000 euid=3000
> debug: leaving helper-app run mode
> debug: Pyzor -> check timed out after 10 secs.
> ==========
>
> Pyzor works fine with SA 2.61, and all other helper-apps (Razor & DCC)
work
> fine with 2.61 and 3.0, and I can still ping the pyzor server - "pyzor
ping"
> comes back with:
> ==========
> 66.250.40.33:24441 (200, 'OK')
> ==========
>
> I am cross-posting this to both the SA and Amavis lists since I am not
sure
> where the issues is. Any feedback or suggestions are most welcome.
>
> Regards,
>
> Bill
>
9011 write(2, "Traceback (most recent call last"..., 35) = -1 EBADF (Bad file
descriptor)
9011 open("/usr/local/bin/pyzor", O_RDONLY|O_LARGEFILE) = 4
9011 write(2, " File \"/usr/local/bin/pyzor"..., 49) = -1 EBADF (Bad file
descriptor)
9011 fstat64(4, {st_mode=S_IFREG|0755, st_size=64, ...}) = 0
9011 old_mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
0) = 0x405ae000
9011 read(4, "#!/usr/local/bin/python\n\nimport "..., 4096) = 64
9011 write(2, " ", 4) = -1 EBADF (Bad file descriptor)
9011 write(2, "pyzor.client.run()\n", 19) = -1 EBADF (Bad file descriptor)
9011 close(4) = 0
9011 munmap(0x405ae000, 4096) = 0
9011 open("/usr/local/lib/python2.3/site-packages/pyzor/client.py",
O_RDONLY|O_LARGEFILE) = 4
9011 write(2, " File \"/usr/local/lib/python2.3"..., 82) = -1 EBADF (Bad file
descriptor)
9011 fstat64(4, {st_mode=S_IFREG|0644, st_size=27835, ...}) = 0
9011 old_mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
0) = 0x405ae000
9011 read(4, "\"\"\"networked spam-signature dete"..., 4096) = 4096
9011 read(4, " debug = 1\n "..., 4096) = 4096
9011 read(4, " for (o, v) in options:\n "..., 4096) = 4096
9011 read(4, "igest\': print_digested,\n "..., 4096) = 4096
9011 read(4, "orm += \"\\n\"\n move"..., 4096) = 4096
9011 read(4, "ert self.curfile is None\n\n "..., 4096) = 4096
9011 read(4, "it__(self, v):\n self.vali"..., 4096) = 3259
9011 write(2, " ", 4) = -1 EBADF (Bad file descriptor)
9011 write(2, "ExecCall().run()\n", 17) = -1 EBADF (Bad file descriptor)
9011 close(4) = 0
9011 munmap(0x405ae000, 4096) = 0
9011 open("/usr/local/lib/python2.3/site-packages/pyzor/client.py",
O_RDONLY|O_LARGEFILE) = 4
9011 write(2, " File \"/usr/local/lib/python2.3"..., 82) = -1 EBADF (Bad file
descriptor)
9011 fstat64(4, {st_mode=S_IFREG|0644, st_size=27835, ...}) = 0
9011 old_mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
0) = 0x405ae000
9011 read(4, "\"\"\"networked spam-signature dete"..., 4096) = 4096
9011 read(4, " debug = 1\n "..., 4096) = 4096
9011 write(2, " ", 4) = -1 EBADF (Bad file descriptor)
9011 write(2, "if not apply(dispatch, (self, ar"..., 38) = -1 EBADF (Bad file
descriptor)
9011 close(4) = 0
9011 munmap(0x405ae000, 4096) = 0
9011 open("/usr/local/lib/python2.3/site-packages/pyzor/client.py",
O_RDONLY|O_LARGEFILE) = 4
9011 write(2, " File \"/usr/local/lib/python2.3"..., 84) = -1 EBADF (Bad file
descriptor)
9011 fstat64(4, {st_mode=S_IFREG|0644, st_size=27835, ...}) = 0
9011 old_mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
0) = 0x405ae000
9011 read(4, "\"\"\"networked spam-signature dete"..., 4096) = 4096
9011 read(4, " debug = 1\n "..., 4096) = 4096
9011 write(2, " ", 4) = -1 EBADF (Bad file descriptor)
9011 write(2, "response = runner.run(server, (d"..., 48) = -1 EBADF (Bad file
descriptor)
9011 close(4) = 0
9011 munmap(0x405ae000, 4096) = 0
9011 open("/usr/local/lib/python2.3/site-packages/pyzor/client.py",
O_RDONLY|O_LARGEFILE) = 4
9011 write(2, " File \"/usr/local/lib/python2.3"..., 82) = -1 EBADF (Bad file
descriptor)
9011 fstat64(4, {st_mode=S_IFREG|0644, st_size=27835, ...}) = 0
9011 old_mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
0) = 0x405ae000
9011 read(4, "\"\"\"networked spam-signature dete"..., 4096) = 4096
9011 read(4, " debug = 1\n "..., 4096) = 4096
9011 read(4, " for (o, v) in options:\n "..., 4096) = 4096
9011 read(4, "igest\': print_digested,\n "..., 4096) = 4096
9011 read(4, "orm += \"\\n\"\n move"..., 4096) = 4096
9011 read(4, "ert self.curfile is None\n\n "..., 4096) = 4096
9011 write(2, " ", 4) = -1 EBADF (Bad file descriptor)
9011 write(2, "response = apply(self.routine, v"..., 48) = -1 EBADF (Bad file
descriptor)
9011 close(4) = 0
9011 munmap(0x405ae000, 4096) = 0
9011 open("/usr/local/lib/python2.3/site-packages/pyzor/client.py",
O_RDONLY|O_LARGEFILE) = 4
9011 write(2, " File \"/usr/local/lib/python2.3"..., 83) = -1 EBADF (Bad file
descriptor)
9011 fstat64(4, {st_mode=S_IFREG|0644, st_size=27835, ...}) = 0
9011 old_mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
0) = 0x405ae000
9011 read(4, "\"\"\"networked spam-signature dete"..., 4096) = 4096
9011 write(2, " ", 4) = -1 EBADF (Bad file descriptor)
9011 write(2, "msg = CheckRequest(digest)\n", 27) = -1 EBADF (Bad file
descriptor)
9011 close(4) = 0
9011 munmap(0x405ae000, 4096) = 0
9011 open("/usr/local/lib/python2.3/site-packages/pyzor/__init__.py",
O_RDONLY|O_LARGEFILE) = 4
9011 write(2, " File \"/usr/local/lib/python2.3"..., 89) = -1 EBADF (Bad file
descriptor)
9011 fstat64(4, {st_mode=S_IFREG|0644, st_size=12430, ...}) = 0
9011 old_mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
0) = 0x405ae000
9011 read(4, "\"\"\"networked spam-signature dete"..., 4096) = 4096
9011 read(4, "nce we\'re dealing with UDP\n "..., 4096) = 4096
9011 read(4, "f.get_code(), self.get_diag())\n\n"..., 4096) = 4096
9011 write(2, " ", 4) = -1 EBADF (Bad file descriptor)
9011 write(2, "typecheck(digest, str)\n", 23) = -1 EBADF (Bad file descriptor)
9011 close(4) = 0
9011 munmap(0x405ae000, 4096) = 0
9011 open("/usr/local/lib/python2.3/site-packages/pyzor/__init__.py",
O_RDONLY|O_LARGEFILE) = 4
9011 write(2, " File \"/usr/local/lib/python2.3"..., 90) = -1 EBADF (Bad file
descriptor)
9011 fstat64(4, {st_mode=S_IFREG|0644, st_size=12430, ...}) = 0
9011 old_mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
0) = 0x405ae000
9011 read(4, "\"\"\"networked spam-signature dete"..., 4096) = 4096
9011 read(4, "nce we\'re dealing with UDP\n "..., 4096) = 4096
9011 read(4, "f.get_code(), self.get_diag())\n\n"..., 4096) = 4096
9011 write(2, " ", 4) = -1 EBADF (Bad file descriptor)
9011 write(2, "raise TypeError\n", 16) = -1 EBADF (Bad file descriptor)
9011 close(4) = 0
9011 munmap(0x405ae000, 4096) = 0
9011 write(2, "TypeError", 9) = -1 EBADF (Bad file descriptor)
9011 rt_sigaction(SIGINT, NULL, {0x4002ede0, [], SA_RESTORER, 0x40181608}, 8)
= 0
9011 rt_sigaction(SIGINT, {SIG_DFL}, NULL, 8) = 0
9011 rt_sigaction(SIGALRM, NULL, {0x4002ede0, [], SA_RESTORER, 0x40181608}, 8)
= 0
9011 rt_sigaction(SIGALRM, {SIG_DFL}, NULL, 8) = 0
9011 close(3) = 0
9011 exit_group(1) = ?
