Bug 6421

So the question is: did spamd fail to send more than 160k of data over SSL,
or did spamc fail to receive it past the indicated size.

Could you repeat the experiment by using a large message and capture the
traffic with 'tcpdump -s 0 -w 0.log ...'. Even though the traffic is encrypted,
the size of transfered data should roughly correspond to the size of a
nonencrypted data. This could provide the answer to the above question.

Glancing over spamd's use of syswrite, I see that it never checks or
reports I/O errors, which is really unforgivable.

- some calls are to syswrite() directly, other through syswrite_full_buffer;
  the later should be used throughout as it caters for partial writes and
  does retries;
- even though syswrite_full_buffer() does check for errors, its caller
  never checks the return value; either the syswrite_full_buffer should be
  modified to log a warning when all retries fails, or the caller should
  do so.

Created attachment 4754 [details]
Tcpdump log as requested

I wanted to attach the result of the tcpdump log, but it looks as it is too big. I did all I could to remove other connections while executing tcdump, but I had to leave on (at least) the ssh connection to the spamd computer and a NFS mount. I've been able to open the log in wireshark, but I have no idea how to extract the total size of the packets passed from spamd to spamc from there (I would be grateful for pointers on that. I understand your time is limited and that is something I should be able to do myself).

I have put the attachment at this address:

http://www.ice.csic.es/files/guerrero/tcdump.log.bz2

Please, tell me when you download it, so I can remove it. The attached file is just a text file with the same address.

On Friday I sent the same attachment directly answering to your message request. I guess that was not the correct procedure, since the message is not appearing in the bug report. I apologize for any inconveniences I may have caused.

Created attachment 4755 [details]
Tcdump log filtered

Playing with wireshark, I've managed to filter out all the communications not originating from spamd on the spamd computer. The result is the attached file, whose size roughly matches the size of the shortened mail, so it looks that spamd is the one not sending all the data. I hope this may help to identify the problem.

Since it is a bit more than two months since the last comment (where I attached the filtered the tcpdumb log), I wanted to ask if there has been any progress on this bug. Has someone been able to reproduce it or/and find a workaround?

Just in case more information is required, the bug (or at least, the unwanted behaviour) continues to be there: the system continues to return cut every message longer than 163770+/-2 bytes. The computer running spamassassin (a 64 bit Debian 5) has been kept updated the whole time and has been rebooted at least twice (so it doesn't look like the problem is related to some incompatibility between, say, library versions loaded in memory and versions on disk) and no other errors (in other protocols or programs) have been detected.

Thaks for your time and attention,

Josep Guerrero

This still continues to baffle me.  I've never seen the sanity check error and check emails all the time larger than ~150KB

Can you list the command line for your spamd?

Also, do you perhaps have anything enforcing memory restraints on Spamd that might be causing issues?

I'm close to considering this a WORKSFORME bug but want to get more information if you are still having the issue.

Hello, I am seeing the exact same issue as the original reporter and am watching this bug for that reason.  I just didn't think I had any more useful information to offer.  A few of my most recent log messages:

Oct 27 13:04:54 canardo spamc[7031]: failed sanity check, 701458 bytes claimed, 163770 bytes seen
Oct 27 13:57:12 canardo spamc[9586]: failed sanity check, 4526382 bytes claimed, 163769 bytes seen
Oct 27 20:14:26 canardo spamc[27097]: failed sanity check, 195214 bytes claimed, 163769 bytes seen
Oct 28 09:15:23 canardo spamc[29946]: failed sanity check, 241547 bytes claimed, 163769 bytes seen
Oct 28 10:17:39 canardo spamc[32734]: failed sanity check, 426548 bytes claimed, 163769 bytes seen
Oct 28 10:27:31 canardo spamc[755]: failed sanity check, 521802 bytes claimed, 163769 bytes seen
Oct 28 11:10:52 canardo spamc[2872]: failed sanity check, 279988 bytes claimed, 163770 bytes seen
Oct 28 18:09:29 canardo spamc[23848]: failed sanity check, 1537235 bytes claimed, 163768 bytes seen

As the original reporter, I am also using SSL between spamc and spamd, and my gut feeling tells me that this may be related to the problem.  As the OR says:  That is probably the only  non-standard setting we use.  



My spamd command line is (with somewhat modified addresses)
/usr/sbin/spamd --username=spamd --max-children 15 --helper-home-dir --allow-tell --nouser-config --sql-config -i -A 127.0.0.1,172.16.185.158,10.138.100.138 --ssl -d --pidfile=/var/run/spamd/spamd.pid


Thanks,
Bjørn

(In reply to comment #6)
> Hello, I am seeing the exact same issue as the original reporter and am
> watching this bug for that reason.  I just didn't think I had any more useful
> information to offer.  A few of my most recent log messages:

Thanks Bjorn.  Knowing others have the issue allows me to justify escalating it.

Can you A) trap a message that exhibits this behavior, B) attach it and C) try it with and without SSL?  I've got a test bed with SSL so I can do the same but I'd like to remove some variables.

Regards,
KAM

It's good to see some activity on this!

Since I reported the bug, the server which runs spamd has been upgraded to 
Debian Squeeze  and now its spamassassin version is 3.3.1(but not the computer 
that runs spamc, which is being kept updated but has not been upgraded) . The 
problem still persists. As far as I can tell, it happens with every message 
over 163770+/-2 bytes (by the way, since most spam is shorter than that, it's 
very easy to overlook the problem). I think it doesn't really matter which 
message it is, only its length, but as soon as I can, I'll send some sample.

I'll see too about trying without ssl, but it may take some time.

My command line is

/usr/sbin/spamd --ssl --create-prefs --max-children 5 -i 172.16.73.20 -A 
172.16.22.20 --helper-home-dir /var/lib/spamassassin/ -s 
/var/lib/spamassassin/spamd.log -d --pidfile=/var/lib/spamassassin/spamd.pid

Thanks again for looking into this.

Josep Guerrero

Created attachment 4999 [details]
Test mail used to trigger the described bug

Created attachment 5000 [details]
Logs showing the bug triggered with --ssl and not triggered without it

I should have done this before, but better late than never...

And I obviously forgot to mention an important part of my setup: I am using
spamass-milter.  The MTA is sendmail.

It seems that spamass-milter is the missing part of the puzzle.  I am not able
to recreate the problem by merely calling spamc directly, even if I give it
input which has previously failed (when spamc was called via spamass-milter).

But resending the same mail via sendmail, having it call spamc through
spamass-milter, will reliably trigger the problem.

In fact, I can reliably trigger it using *any* sufficienly large enough mail as
long as it goes through spamass-milter.  But --ssl also affects this.  The
problem does not show up unless I use --ssl between spamass-milter and spamd.

I am attaching a completely dummy "test.mail" which does trigger the problem
for me, as long as it is passed via ssl to spamd by spamass-milter. The mail
contains nothing but a large enough file full of null bytes.  My tests
indicates that the actual contents doesn't matter, just the size.

I am also attaching "spamd-spamc-sendmail-log.txt" with logs showing
"test.mail" received twice: first using --ssl and failing, and then without
--ssl and working.

Note that I sent it to an external address which is forwarded back to me, as my
setup won't normally scan anything received from a host on the local network.
This was just done so because it was simpler than modifying the setup to make
spamass-milter scan local mail.



Bjørn

Hello!

Just to add more data, after reading Bjørn messages:

* I'm not using spamass-milter. It's not even installed on the servers.
* I'm using postfix as mail server
* This is the spamc command I use from within postfix:

spamassassin unix -     n       n       -       -       pipe
        user=nobody argv=/usr/bin/spamc -u ${user} -S -d 172.16.73.20 -s 500000 -e /usr/sbin/sendmail -oi -f ${sender} ${recipient}

Josep Guerrero

I tried this on our system (openssl-1.0.1_2) and a 4 MB message was
successfully passed from spamc to spamd over ssl.

Even though the reason for a spamc cutoff threshold of about 160 kB
on reporter's systems remains unexplained, looking as the libspamc.c
code I can see that calls to SSL_write (and other SSL routines) lack
any status checking, so anything is possible and any error reported
by openssl remains stashed under a carpet. Not good.

In general the SSL code in spamc is in need of modernization and deprecation of things like SSLv3.

However, the +/- bytes issue is not repeatable for me.  I've checked 60 days of logs and the only failed sanity checks that I have are caused by service interruptions on the spamd side.

If you still have the issue with 3.4+, let us know.

I'm now using Debian Wheezy, with spamassassin 3.3.2 both in the spamc client and the spamd daemon, and the issue still happens. Since the new Debian version, Jessie, is scheduled to appear in a few weeks, I may be able to try soon a newer version of spamassassin. On the other hand, a few weeks ago I decided to remove the ssl communication and use only unencrypted communication between both computers, and the issue disappeared, so at least I can confirm that, whatever happens, it is ssl related.

Reopening as a likely bug in SSL.

Pushing to 3.4.3

Closing stale bug