bugSpamAssassin Milter Plugin - Bugs: bug #15999, spamass-milter 0.3.0 crashes after...

 
 

bug #15999: spamass-milter 0.3.0 crashes after a random time

Submitted by:  None
Submitted on:  Sun 05 Mar 2006 01:34:35 PM UTC  
Votes:  50  
 
Category: NoneSeverity: 3 - Normal
Item Group: NoneStatus: None
Privacy: PublicAssigned to: None
Open/Closed: Open

Add a New Comment (Rich MarkupRich Markup):
   

You are not logged in

Please log in, so followups can be emailed to you.

 

(Jump to the original submission Jump to the original submission)

Fri 01 Jun 2007 01:45:12 AM UTC, comment #16:

Duh. A bug in my per-user modification, it was crashing every time
mail was to an alias

Andrew

Andrew Daviel <adaviel>
Thu 31 May 2007 01:16:12 AM UTC, comment #15:

Me, too. I ran version 0.20 at home; it died occasionally and I restarted it from cron. Now I installed it on our mailserver at work and it dies after a few minutes at most. I upgraded to 0.3.1
and it still dies. I tried increasing times to 20m as per comment #14 but little different.
SpamAssassin 3.1.8, sendmail-8.13.1-3.2 on RedHat Enterprise Linux 4.3

sendmail logs: milter_read(spamassassin): cmd read returned 0, expecting 5

Andrew Daviel <adaviel>
Tue 14 Nov 2006 02:22:27 AM UTC, comment #14:

I'm experiencing the same problem under sendmail on a RHEL server. I've found that increasing the following values in sendmail.mc

F=,T=C:15m;S:4m;R:4m;E:10m

to all be 20 has reduced the crashes considerably.

ie - F=, T=C:20m;S:20m;R:20m;E:20m

Anonymous
Wed 03 May 2006 10:29:45 AM UTC, comment #13:

Hi Dan. The system is FreeBSD 6.0-RELEASE-p6 with the generic kernel, Sendmail 8.13.4, and SpamAssassin 3.1.1.

FWIW, I rewrote spamass-milter in Python (based on http://www.bmsi.com/python/milter.html) last Thursday afternoon in order to get some site specific behaviour and cure this problem. The Python version doesn't seem to have the same problem, though I haven't had the time to investigate why. The Python milter module makes the same kind of call to smfi_main() but this never returns, whereas smfi_main() called from spamass-milter appears to be doing so after the connection problem. It's possible that the Python code is masking rather than curing the problem, but so far it hasn't quit and opened the spam floodgates.

Richard Brooksby <rptb1>
Thu 27 Apr 2006 02:58:54 PM UTC, comment #12:

That doesn't look like the same problem, Richard. In your case, spamass-milter is exiting cleanly because sendmail's connections to it are failing for some reason. It looks like sendmail's milter code returns ERANGE when your system doesn't have the poll() syscall and the file descripter returned by accept is greater than FD_SETSIZE (meaning it can't be processed by the select syscall). What OS and sendmail versions are you running, and if you run lsof on the spamass-milter process a couple hours after it is started, how many open filedescriptors are there (should be less than 20 on most systems)?

Dan Nelson <dnelson>
Project Administrator
Thu 27 Apr 2006 10:55:49 AM UTC, comment #11:

We're seeing exactly the same thing here. A little before the errors listed above we see this in our logs:

Apr 27 01:23:03 raven spamass-milter[75775]: SpamAssassin: accept() returned invalid socket (Result too large), try again
Apr 27 01:23:17 raven spamass-milter[75775]: SpamAssassin: accept() returned invalid socket (Result too large), try again
Apr 27 01:23:32 raven spamass-milter[75775]: SpamAssassin: accept() returned invalid socket (Result too large), abort
Apr 27 01:23:48 raven spamass-milter[75775]: spamass-milter 0.3.0 exiting
Apr 27 01:24:16 raven sm-mta[12825]: k3R0OGL0012825: Milter (spamassassin): error connecting to filter: Connection refused by /var/run/spamass-milter.sock
Apr 27 01:25:13 raven sm-mta[12843]: k3R0PDwi012843: Milter (spamassassin): error connecting to filter: Connection refused by /var/run/spamass-milter.sock
Apr 27 01:26:50 raven sm-mta[12867]: k3R0QoCb012867: Milter (spamassassin): error connecting to filter: Connection refused by /var/run/spamass-milter.sock

Richard Brooksby <rptb1>
Tue 28 Mar 2006 03:34:53 PM UTC, comment #10:

I have a patch for the header problem in CVS; until I release a new version (next week) you should be able to drop the FreeBSD ports patch into your pkgsrc files/ directory and rebuild:

http://www.freebsd.org/cgi/cvsweb.cgi/ports/mail/spamass-milter/files/patch-spamass-milter.cpp?rev=1.8

Dan Nelson <dnelson>
Project Administrator
Tue 28 Mar 2006 09:43:01 AM UTC, comment #9:

Please disregard comment #8, it just took a long(er) time to crash. Sorry.

Jaap Boender <semprini>
Tue 21 Mar 2006 01:34:23 PM UTC, comment #8:

Hmm. I noticed in my logs some errors about lockfiles, things like
Mar 17 00:01:05 courbet lmtpunix[17366]: locking disabled: couldn't open socket
lockfile /var/imap/config/socket/lmtpunix-0.lock: No such file or directory.
I've fixed that, and spamass-milter has been running for two days without a core dump, so I'm hesitantly beginning to think that it solved the problems. (The disadvantage is that now I get mails where somehow the headers are rearranged, with a newline in the middle, but that seems to be another error entirely...)

Jaap Boender <semprini>
Mon 20 Mar 2006 09:49:04 AM UTC, comment #7:

Here we go:
(gdb) frame 5
#5 0x0000000120001c08 in assassinate(smfi_str, SpamAssassin) (
ctx=0x1201402f0, assassin=0x162dffe98) at spamass-milter.cpp:571
571 throw string("error. could not replace body.");
(gdb) info locals
eoh1 = 751
eoh2 = 0
bob = 753
(gdb) frame 6
#6 0x00000001200059e4 in mlfi_eom(smfi_str*) (ctx=0x120146000)
at spamass-milter.cpp:1166
1166 milter_status = assassinate(ctx, assassin);
(gdb) print *assassin
$1 = {error = false, running = false, connected = true, mail = {
static npos = 18446744073709551615,
_M_dataplus = {<allocator<char>> = {<No data fields>},
_M_p = 0x12015a018 "Received: from localhost by courbet.kerguelen.org\n\twith SpamAssassin (version 3.1.0);\n\tFri, 17 Mar 2006 11:25:54 +0100\nFrom: \"Bart Bryson\" <kelsmanazgm@aurora.edu>\r\nTo: <MY_EMAIL_ADDRESS>\r\nSubject:"...}, static _S_empty_rep_storage = {0, 0, 2, 0}}, outputbuffer = {
static npos = 18446744073709551615,
_M_dataplus = {<allocator<char>> = {<No data fields>},
_M_p = 0x120154018 ""}, static _S_empty_rep_storage = {0, 0, 2, 0}},
x_spam_status = {static npos = 18446744073709551615,
_M_dataplus = {<allocator<char>> = {<No data fields>},
_M_p = 0x120146218 "Yes, score=12.7 required=5.0 tests=BAYES_99,INFO_TLD,\n\tRCVD_NUMERIC_HELO,SUBJECT_NOVOWEL,URIBL_JP_SURBL,URIBL_WS_SURBL \n\tautolearn=no version=3.1.0"}, static _S_empty_rep_storage = {0, 0, 2, 0}},
x_spam_flag = {static npos = 18446744073709551615,
_M_dataplus = {<allocator<char>> = {<No data fields>},
_M_p = 0x1201528d8 "YES"}, static _S_empty_rep_storage = {0, 0, 2, 0}},
x_spam_report = {static npos = 18446744073709551615,
_M_dataplus = {<allocator<char>> = {<No data fields>},
_M_p = 0x120138a60 ""}, static _S_empty_rep_storage = {0, 0, 2, 0}},
x_spam_prev_content_type = {static npos = 18446744073709551615,
_M_dataplus = {<allocator<char>> = {<No data fields>},
_M_p = 0x120138a60 ""}, static _S_empty_rep_storage = {0, 0, 2, 0}},
x_spam_checker_version = {static npos = 18446744073709551615,
_M_dataplus = {<allocator<char>> = {<No data fields>},
_M_p = 0x120152b58 "SpamAssassin 3.1.0 (2005-09-13) on \n\tcourbet.kerguelen.org"}, static _S_empty_rep_storage = {0, 0, 2, 0}}, x_spam_level = {
static npos = 18446744073709551615,
_M_dataplus = {<allocator<char>> = {<No data fields>},
_M_p = 0x12014b070 '*' <repeats 12 times>},
static _S_empty_rep_storage = {0, 0, 2, 0}}, _content_type = {
static npos = 18446744073709551615,
_M_dataplus = {<allocator<char>> = {<No data fields>},
_M_p = 0x120152c08 "multipart/mixed; boundary=\"----------=_441A8EB2.4F94DAB8\""}, static _S_empty_rep_storage = {0, 0, 2, 0}}, _subject = {
static npos = 18446744073709551615,
_M_dataplus = {<allocator<char>> = {<No data fields>},
_M_p = 0x120152088 "$EXUALLY EXPLlClTT: Have you ever seen beauteous girls get fuckked in every holes?"}, static _S_empty_rep_storage = {0, 0, 2, 0}},
_from = {static npos = 18446744073709551615,
_M_dataplus = {<allocator<char>> = {<No data fields>},
_M_p = 0x120150b28 "<kelsmanazgm@aurora.edu>"},
static _S_empty_rep_storage = {0, 0, 2, 0}}, _rcpt = {
static npos = 18446744073709551615,
_M_dataplus = {<allocator<char>> = {<No data fields>},
_M_p = 0x12014a928 "<MY_EMAIL_ADDRESS>"},
static _S_empty_rep_storage = {0, 0, 2, 0}}, _connectip = {
static npos = 18446744073709551615,
_M_dataplus = {<allocator<char>> = {<No data fields>},
_M_p = 0x1201481f8 "213.235.35.22"}, static _S_empty_rep_storage = {0,
0, 2, 0}}, _numrcpt = 1,
recipients = {<_List_base<std::basic_string<char, std::char_traits<char>, std::allocator<char> >,std::allocator<std::basic_string<char, std::char_traits<char>, std::allocator<char> > > >> = {<_List_alloc_base<std::basic_string<char, std::char_traits<char>, std::allocator<char> >,std::allocator<std::basic_string<char, std::char_traits<char>, std::allocator<char> > >,true>> = {
_M_node = 0x120148000}, <No data fields>}, <No data fields>},
expandedrcpt = {<_List_base<std::basic_string<char, std::char_traits<char>, std::allocator<char> >,std::allocator<std::basic_string<char, std::char_traits<char>, std::allocator<char> > > >> = {<_List_alloc_base<std::basic_string<char, std::char_traits<char>, std::allocator<char> >,std::allocator<std::basic_string<char, std::char_traits<char>, std::allocator<char> > >,true>> = {
_M_node = 0x120148018}, <No data fields>}, <No data fields>},
queueid = {static npos = 18446744073709551615,
_M_dataplus = {<allocator<char>> = {<No data fields>},
_M_p = 0x120148220 "k2HAKm1Y006613"}, static _S_empty_rep_storage = {0,
0, 2, 0}}, pid = 23570, pipe_io = {{-1, -1}, {-1, -1}}}

I've replaced my e-mail address with MY_EMAIL_ADDRESS - I'm receiving enough spam as it is...

Jaap Boender <semprini>
Fri 17 Mar 2006 06:08:50 PM UTC, comment #6:

That's a more interesting stack trace. Here we see an exception raised at spamass-milter.cpp:571, due to smfi_replacebody failing. The call to assassinate() at line 1166 is wrapped in a try/catch block, though, so the exception should have been caught and should have simply resulted in the milter failing to process that message. It shouldn't have aborted. Then again, smfi_replacebody shouldn't have failed, either. http://www.milter.org/milter_api/smfi_replacebody.html lists 4 possibilities for it failing, the only likely one being "A network error occurs", which isn't much help.

Could you run "info locals" from frame 5, and "print *assassin" from frame 6 of that coredump?

Dan Nelson <dnelson>
Project Administrator
Fri 17 Mar 2006 11:48:31 AM UTC, comment #5:

I already threw away the core dump, stupidly enough, and I can't seem to reproduce it faithfully. But here is another one, and it mentions line 1166:

Thread 4 (Thread 27 ()):
#0 0x000000012008a108 in kill ()
#1 0x00000001200bc364 in abort ()
#2 0x000000012007a174 in uw_init_context_1 ()
#3 0x000000012007a504 in _Unwind_RaiseException ()
#4 0x00000001200573f8 in __cxa_throw ()
#5 0x0000000120001c08 in assassinate(smfi_str, SpamAssassin) (
ctx=0x1201402f0, assassin=0x162dffe98) at spamass-milter.cpp:571
#6 0x00000001200059e4 in mlfi_eom(smfi_str*) (ctx=0x120146000)
at spamass-milter.cpp:1166
#7 0x0000000120010e24 in mi_clr_macros ()
#8 0x000000012000fe88 in mi_engine ()
warning: Hit heuristic-fence-post without finding
warning: enclosing function for address 0x162c00000

(thread 3 and 2 are the same as for the other dumps, thread 1 is the same as thread 4)

According to my GDB, however, line 1166 is
1166 milter_status = assassinate(ctx, assassin);
The NetBSD version of spamass-milter is in fact slightly patched from 0.3.0, which might explain the difference.

info locals on frame 6 of the above trace gives:
assassin = (SpamAssassin *) 0x120146100
milter_status = 1658847064

I did save the core this time, so if you need more information, please ask...

Jaap Boender <semprini>
Thu 16 Mar 2006 04:20:00 PM UTC, comment #4:

Odd. spamass-milter.cpp:1166 is the closing brace of the mlfi_eoh function, but your stack shows that mlfi_eom is calling abort.

Usually when the stack trace points to the end of a function, the crash occured in a destructor (afaik there's no way to know what variable was being processed at the time of the crash).

If the netbsd valgrind port were complete, I'd suggest running under that, since it's pretty good at indicating what the problem is.

Could you try attaching to the last core, and run "frame 2", then "info locals" ? That should print the active variables at the time mlfi_eom() called abort(). One of them should be the culprit.

Dan Nelson <dnelson>
Project Administrator
Thu 16 Mar 2006 02:01:16 PM UTC, comment #3:

The next core dump is slightly different:

Thread 4 (Thread 23 ()):
#0 0x000000012008a108 in kill ()
#1 0x00000001200bc364 in abort ()
#2 0x00000001200059e4 in mlfi_eom(smfi_str*) (ctx=0x162dffe30)
at spamass-milter.cpp:1166
warning: Hit beginning of text section without finding
warning: enclosing function for address 0x80

(...; threads 3 and 2 are the same)

Thread 1 (LWP 6):
#0 0x000000012008a108 in kill ()
#1 0x00000001200bc364 in abort ()
#2 0x00000001200059e4 in mlfi_eom(smfi_str*) (ctx=0x162dffe30)
at spamass-milter.cpp:1166
warning: Hit beginning of text section without finding
warning: enclosing function for address 0x80
#0 0x000000012008a108 in kill ()

Jaap Boender <semprini>
Thu 16 Mar 2006 01:46:05 PM UTC, comment #2:

No, there is nothing below the abort, but a thread apply all bt gives:

Thread 4 (Thread 32 ()):
#0 0x000000012008a108 in kill ()
#1 0x00000001200bc364 in abort ()

Thread 3 (LWP 2):
#0 0x000000012008c0ec in __sigtimedwait ()
#1 0x000000012007e6f0 in sigtimedwait ()
#2 0x000000012008a4c8 in sigwait ()
#3 0x000000012000e314 in mi_clean_signals ()
#4 0x00000001200830ec in pthread_create ()

Thread 2 (LWP 5):
#0 0x0000000120089f7c in _sys_select ()
#1 0x000000012007d3d4 in select ()
#2 0x000000012000f44c in mi_listener ()
#3 0x000000012000e15c in smfi_main ()
#4 0x0000000120000ab8 in main (argc=6, argv=0x1200d8af2)
at spamass-milter.cpp:353

Thread 1 (LWP 4):
#0 0x000000012008a108 in kill ()
#1 0x00000001200bc364 in abort ()
#0 0x000000012008a108 in kill ()

Jaap Boender <semprini>
Mon 06 Mar 2006 03:44:15 PM UTC, comment #1:

There's nothing in the trace below the abort()? How about any other threads ("thread apply all bt" in gdb)? spamass-milter doesn't ever call abort itself, so something else must be doing it, either the sendmail code or maybe malloc if it detects that memory has been stepped on. Try rebuilding with debugging and/or running it under gdb directly to get a better stack trace.

Dan Nelson <dnelson>
Project Administrator
Sun 05 Mar 2006 01:34:35 PM UTC, original submission:

I'm using spamass-milter 0.3.0 (from the NetBSD pkgsrc) on NetBSD/alpha 3.0, but it crashes with a SIGABRT after a random time. I've tried recompiling with -static, and compiling sendmail without IPv6 support, but both didn't work. I've also tried adjusting the number of spamassassin clients upwards, but no luck there either.

In the maillog, I see messages like:
Mar 5 13:56:48 courbet sm-mta[5143]: k25CumUQ005143: Milter (spamassassin): error connecting to filter: Connection refused by /var/run/spamass.sock
Mar 5 13:56:48 courbet sm-mta[5143]: k25CumUQ005143: Milter (spamassassin): to error state

but they in themselves do not seem to cause a crash, because there are multiple of them, until at some point spamass-milter just crashes. The core dump is not much use either, it just shows abort() and kill()...

Anonymous

 

(Note: upload size limit is set to 16384 kB, after insertion of the required escape characters.)

Attach File(s):
   
   
Comment:
   

No files currently attached

 

Depends on the following items: None found

Items that depend on this one: None found

 

Carbon-Copy List
  • -unavailable- added by adaviel (Posted a comment)
  •  

    Do you think this task is very important?
    If so, you can click here to add your encouragement to it.
    This task has 50 encouragements so far.

    Only logged-in users can vote.

     

    Please enter the title of George Orwell's famous dystopian book (it's a date):

     

     

    Follow 2 latest changes.

    Date Changed By Updated Field Previous Value => Replaced By
    Thu 27 Apr 2006 10:53:23 AM UTCrptb1Carbon-Copy-=>Added rptb1
    Thu 16 Mar 2006 10:26:24 AM UTCsempriniCarbon-Copy-=>Added semprini

    Back to the top


    Powered by Savane 3.1-cleanup