You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@spamassassin.apache.org by bu...@bugzilla.spamassassin.org on 2010/02/26 00:04:40 UTC

[Bug 6351] New: Pyzor plugin fails with "check failed: no response" even though pyzor seems to work okay

https://issues.apache.org/SpamAssassin/show_bug.cgi?id=6351

           Summary: Pyzor plugin fails with "check failed: no response"
                    even though pyzor seems to work okay
           Product: Spamassassin
           Version: 3.3.0
          Platform: Other
        OS/Version: Linux
            Status: NEW
          Severity: major
          Priority: P5
         Component: Plugins
        AssignedTo: dev@spamassassin.apache.org
        ReportedBy: erik@logtenberg.eu


I configured SpamAssassin with the Pyzor plugin, following the HOWTO's:

http://wiki.apache.org/spamassassin/UsingPyzor

When I test it, the Pyzor plugin doesn't seem to work however:

# echo hoi | su spamd -c 'spamassassin -D pyzor'
feb 25 23:42:46.297 [1653] dbg: pyzor: network tests on, attempting Pyzor
feb 25 23:42:49.447 [1653] dbg: pyzor: pyzor is available: /usr/bin/pyzor
feb 25 23:42:49.448 [1653] dbg: pyzor: opening pipe: /usr/bin/pyzor check <
/tmp/.spamassassin1653RDuT3etmp
feb 25 23:42:49.514 [1653] dbg: pyzor: [1654] finished: exit 1
feb 25 23:42:49.515 [1653] dbg: pyzor: check failed: no response

I added some extra debug statements to the perl module:

/usr/lib/perl5/vendor_perl/5.10.0/Mail/SpamAssassin/Plugin/Pyzor.pm

and traced this down to the pyzor_lookup function, where the pyzor binary is
actually called:

    $pid = Mail::SpamAssassin::Util::helper_app_pipe_open(*PYZOR,
        $tmpf, 1, $path, split(' ', $opts), "check");
    $pid or die "$!\n";

    # read+split avoids a Perl I/O bug (Bug 5985)
    my($inbuf,$nread,$resp); $resp = '';
    while ( $nread=read(PYZOR,$inbuf,8192) ) { $resp .= $inbuf }
    defined $nread  or die "error reading from pipe: $!";
    @response = split(/^/m, $resp, -1);  undef $resp;

In this code snippet, $resp actually stays empty, the while statement doesn't
execute its body even once. I tried reverting the fix for bug 5985 by replacing
the second part of this code to the original:

    $! = 0; @response = <PYZOR>;
    $!==0  or die "error reading from pipe: $!";

However also in this case @response stayed empty. Ofcourse I also looked up the
helper_app_pipe_open function in Util.pm (which is also used for the DCC
plugin), but that function is too complex for me to successfully debug.


Now I'm quite positive that Pyzor actually does work and in fact does return
output, because when ran separately, I get the following:

# su spamd -c '/usr/bin/pyzor check < /tmp/.spamassassin11143hdfCkYtmp'
public.pyzor.org:24441  (200, 'OK')     0       0

So you see that Pyzor is configured correctly, it has discovered its servers
and saved that in its homedirectory just fine. It is able to connect to the
server and it returns 200 OK and in this case a spam score of 0. I would expect
SA to receive output like this, but apparently that doesn't happen.

According to the SA debug output, Pyzor even returned an exit code of 1. By
running Pyzor manually I haven't been able to reproduce such an exit code. I
did notice that there is quite some perl code between the debug statement that
says what command it's going to execute and the part where that command is
actually executed. There's some fiddling with the command line arguments which
I haven't tried to understand just yet. I can imagine that the actual command
executed differs in some way from the command shown in the debug statement.

This is Fedora 12 x86_64, spamassassin-3.3.0-51.fc12.x86_64 (from Atrpms, but
spamassassin-3.3.0-5.fc12.x86_64 from Fedora itself has the same issue) and
pyzor-0.5.0-3.fc12.noarch.

-- 
Configure bugmail: https://issues.apache.org/SpamAssassin/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

[Bug 6351] Pyzor plugin fails with "check failed: no response" even though pyzor seems to work okay

Posted by bu...@bugzilla.spamassassin.org.
https://issues.apache.org/SpamAssassin/show_bug.cgi?id=6351

--- Comment #2 from Mark Martinec <Ma...@ijs.si> 2010-03-01 18:26:51 UTC ---
> Very shortly after finishing reading the tempfile, pyzor quits, and SA reports
> the "exit 1" status. I can't figure out by looking at the strace what went
> wrong, but maybe someone else has a clue.
[...]
> It seems that pyzor hasn't even contacted the server yet, apparently something
> went wrong before that.

Your analysis seems correct, pyzor stops without writing anything back.

Sorry, but I have no idea why. Perhaps adding a '-d' debug option to
pyzor_options might tell more. Or even adding a python '-d' option
to the first (hash-bang) line of a pyzor program - or turning on
one of the python debug/verbose environment variables.

-- 
Configure bugmail: https://issues.apache.org/SpamAssassin/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

[Bug 6351] Pyzor plugin fails with "check failed: no response" even though pyzor seems to work okay

Posted by bu...@bugzilla.spamassassin.org.
https://issues.apache.org/SpamAssassin/show_bug.cgi?id=6351

Matthijs Kooijman <ma...@stdin.nl> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |matthijs@stdin.nl

--- Comment #4 from Matthijs Kooijman <ma...@stdin.nl> ---
The https://wiki.apache.org/spamassassin/UsingPyzor page says: The "check
failed: no response" does not indicate a problem, as this test does not pass in
an actual properly-formatted email message.

So it seems the problem is in your testcase, not in SA?

-- 
You are receiving this mail because:
You are the assignee for the bug.

[Bug 6351] Pyzor plugin fails with "check failed: no response" even though pyzor seems to work okay

Posted by bu...@issues.apache.org.
https://issues.apache.org/SpamAssassin/show_bug.cgi?id=6351

David Hill <hi...@binarystorm.net> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |hilld@binarystorm.net

--- Comment #3 from David Hill <hi...@binarystorm.net> 2010-04-19 03:35:50 EDT ---
(In reply to comment #2)
> > Very shortly after finishing reading the tempfile, pyzor quits, and SA reports
> > the "exit 1" status. I can't figure out by looking at the strace what went
> > wrong, but maybe someone else has a clue.
> [...]
> > It seems that pyzor hasn't even contacted the server yet, apparently something
> > went wrong before that.
> 
> Your analysis seems correct, pyzor stops without writing anything back.
> 
> Sorry, but I have no idea why. Perhaps adding a '-d' debug option to
> pyzor_options might tell more. Or even adding a python '-d' option
> to the first (hash-bang) line of a pyzor program - or turning on
> one of the python debug/verbose environment variables.

I had the very same problem ... Just noticed my pyzor was broken.

What I did, as I'm using debian, I "su - Debian-exim - /bin/bash" and then ran
"pyzor discover" ...

Fixed my problem.

I looked in my log files, and it was broken since a little bit.  Only working
one was DCC and RAZOR... :S

-- 
Configure bugmail: https://issues.apache.org/SpamAssassin/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

[Bug 6351] Pyzor plugin fails with "check failed: no response" even though pyzor seems to work okay

Posted by bu...@bugzilla.spamassassin.org.
https://issues.apache.org/SpamAssassin/show_bug.cgi?id=6351

erik@logtenberg.eu changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |erik@logtenberg.eu

--- Comment #1 from erik@logtenberg.eu 2010-03-01 16:57:28 UTC ---
Additional information:

I strace'd spamc using -f to follow the pyzor-fork. In the trace I see SA
opening a temporary file in /tmp and writing the mail to it, then starting
pyzor and feeding it the tempfile. Pyzor starts fine, reads its configuration
file(s) (especially the servers file, which in my case is the only relevant
configuration file), and then starts reading the tempfile.

Very shortly after finishing reading the tempfile, pyzor quits, and SA reports
the "exit 1" status. I can't figure out by looking at the strace what went
wrong, but maybe someone else has a clue. This is the strace, starting with the
final "read", which is Pyzor reading the tempfile, and ending with the "write"
where SA echo's the debug message:

[pid 29868] read(0, "AADrDAAA7AwAAO0MAADuDAAA7wwA\nAPA"..., 4096) = 4096
[pid 29868] read(0, "AAOEPAADiDwAA\n4w8AAOQPAADlDwAA5g"..., 4096) = 3682
[pid 29868] close(4)                    = 0
[pid 29868] munmap(0x7f2adb25b000, 4096) = 0
[pid 29868] close(3)                    = 0
[pid 29868] rt_sigaction(SIGINT, {SIG_DFL, [], SA_RESTORER, 0x3003e0f0f0},
{0x300570b2b0, [], SA_RESTORER, 0x3003e0f0f0}, 8) = 0
[pid 29868] rt_sigaction(SIGALRM, {SIG_DFL, [], SA_RESTORER, 0x3003e0f0f0},
{0x300570b2b0, [], SA_RESTORER, 0x3003e0f0f0}, 8) = 0
[pid 29868] exit_group(1)               = ?
Process 29868 detached
[pid 29867] <... read resumed> "", 4096) = 0
[pid 29867] close(5)                    = 0
[pid 29867] rt_sigaction(SIGHUP, {SIG_IGN, [], SA_RESTORER, 0x3003e0f0f0},
{0x7f36e599be80, [], SA_RESTORER, 0x3003e0f0f0}, 8) = 0
[pid 29867] rt_sigaction(SIGINT, {SIG_IGN, [], SA_RESTORER, 0x3003e0f0f0},
{0x7f36e599be80, [], SA_RESTORER, 0x3003e0f0f0}, 8) = 0
[pid 29867] rt_sigaction(SIGQUIT, {SIG_IGN, [], SA_RESTORER, 0x3003e0f0f0},
{SIG_DFL, [], 0}, 8) = 0
[pid 29867] wait4(29868, [{WIFEXITED(s) && WEXITSTATUS(s) == 1}], 0, NULL) =
29868
[pid 29867] --- SIGCHLD (Child exited) @ 0 (0) ---
[pid 29867] rt_sigaction(SIGHUP, {0x7f36e599be80, [], SA_RESTORER,
0x3003e0f0f0}, NULL, 8) = 0
[pid 29867] rt_sigaction(SIGINT, {0x7f36e599be80, [], SA_RESTORER,
0x3003e0f0f0}, NULL, 8) = 0
[pid 29867] rt_sigaction(SIGQUIT, {SIG_DFL, [], SA_RESTORER, 0x3003e0f0f0},
NULL, 8) = 0
[pid 29867] gettimeofday({1267461624, 844985}, NULL) = 0
[pid 29867] stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2917, ...}) =
0
[pid 29867] gettimeofday({1267461624, 845364}, NULL) = 0
[pid 29867] stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2917, ...}) =
0
[pid 29867] stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2917, ...}) =
0
[pid 29867] write(2, "mrt  1 17:40:24.845 [29867] dbg:"..., 65mrt  1
17:40:24.845 [29867] dbg: pyzor: [29868] finished: exit 1

Please note that 29867 is SA and 29868 is pyzor.

It seems that pyzor hasn't even contacted the server yet, apparently something
went wrong before that. However I don't know what - as I said in my previous
post: when I start pyzor manually with the same arguments and using the same
user id, it works fine.

-- 
Configure bugmail: https://issues.apache.org/SpamAssassin/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.