#22 dk-milter v0.2.6 (+PATCH) to errorstate then SMTP is RESETed

v0.2.6
closed
5
2005-03-08
2005-02-24
No

The function of dk-filters is discarded due to failure
of the filter then sending peer resets the SMTP-session.
Here is the output from a fairly recent logfile...

Feb 24 08:43:25 aries sendmail[8078]: [ID 801593
mail.info] j1O7hPfW008078: Milter (sid-filter): init
success to negotiate
Feb 24 08:43:42 aries sendmail[8078]: [ID 801593
mail.error] j1O7hPfW008078: Milter (dk-filter): read
returned -1: Connection reset by [218.108.155.49]
Feb 24 08:43:42 aries sendmail[8078]: [ID 801593
mail.info] j1O7hPfW008078: Milter (dk-filter): to error
state
Feb 24 08:43:42 aries sendmail[8078]: [ID 801593
mail.error] j1O7hPfW008078: Milter (dk-filter): init
failed to open
Feb 24 08:43:42 aries sendmail[8078]: [ID 801593
mail.info] j1O7hPfW008078: Milter (dk-filter): to error
state
Feb 24 08:43:42 aries sendmail[8078]: [ID 801593
mail.info] Feb 24 08:43:42 aries sendmail[8078]: [ID
801593 mail.info] j1O7hPfW008078: Milter: connect to
filters
Feb 24 08:43:48 aries sendmail[8078]: [ID 801593
mail.info] j1O7hPfW008078: Authentication-Warning:
aries.vattenfall.se: Host [218.108.155.49] claimed to
be snr-realty.com
Feb 24 08:44:04 aries milter-greylist: [ID 902575
mail.info] j1O7hPfW008078: skipping greylist because
this is the default action,
(from=<Breanna3veo@e-kolay.net>,
rcpt=<mko@forsmark.vattenfall.se>, addr=218.108.155.49)
Feb 24 08:44:09 aries sendmail[8078]: [ID 801593
mail.info] j1O7hPfW008078:
from=<Breanna3veo@e-kolay.net>, size=2410, class=0,
nrcpts=1,
msgid=<100101c51a44$e3a93f93$429e65ca@e-kolay.net>,
proto=ESMTP, daemon=MTA-v4, relay=[218.108.155.49]
Feb 24 08:44:09 aries sendmail[8078]: [ID 801593
mail.info] j1O7hPfW008078: Milter insert (1): header:
X-SenderID: Sendmail Sender-ID Filter v0.2.5
mx1.vattenfall.se j1O7hPfW008078
Feb 24 08:44:09 aries sendmail[8078]: [ID 801593
mail.info] j1O7hPfW008078: Milter insert (1): header:
Authentication-Results: mx1.vattenfall.se
from=Breanna3veo@e-kolay.net; sender-id=neutral;
spf=neutral
(mx1.vattenfall.se [192.36.28.1]); Thu, 24 Feb 2005
08:44:09 +0100 (MET)
Feb 24 08:44:09 aries sendmail[8078]: [ID 801593
mail.info] j1O7hPfW008078: Milter accept: message
Feb 24 08:44:21 aries sendmail[8213]: [ID 801593
mail.info] j1O7hPfW008078:
to=<mko@forsmark.vattenfall.se>, delay=00:00:17,
xdelay=00:00:12, mailer=relay, pri=122410,
relay=orion.vattenfall.se. [151.156.10.12], dsn=2.0.0,
stat=Sent (j1O7i94P016603 Message accepted for delivery)

Discussion

  • Anonymous - 2005-02-24

    Logged In: YES
    user_id=1048957

    I'm not sure I understand what you're reporting here. It
    looks to me like you're reporting a filter crash (that's
    what the log shows) but the SMTP session continues normally.

    If I connect to my home domain's SMTP server, which is
    running dk-filter 0.2.6, and inject part of a message but
    then disconnect, there's no error like this in my log file.

    What are the steps I need to follow to reproduce this?

     
  • Anonymous - 2005-02-24
    • labels: --> Functionality
    • milestone: --> v0.2.6
    • assigned_to: nobody --> sm-msk
     
  • Fredrik Pettai

    Fredrik Pettai - 2005-02-28

    Logged In: YES
    user_id=370342

    Sorry for the delay, but your presumption is correct.
    The dk-filter craches but the SMTP-session contiues.

    I'm not sure how to reproduce this error. Apparently
    dk-filter craches hard and never wake up. But no core is
    produced...

    I will do a little thinking about it. Maybe i should but i
    F=T in the sendmail.cf for the milterplugin so i will see
    which stranges mails that are rejected due to filtercrashes.

    Re,
    /P

     
  • Fredrik Pettai

    Fredrik Pettai - 2005-02-28

    Logged In: YES
    user_id=370342

    Another example in the log of just a common mail, that makes
    dk-filter fail...I will see if i can get the mail from the user.

    Re,
    /P

    Feb 24 21:23:32 libra sendmail[3194]: [ID 801593 mail.error]
    j1OKMQte003194: Milter (dk-filter): read returned -1:
    Connection reset by mail98.messagelabs.com
    Feb 24 21:23:32 libra sendmail[3194]: [ID 801593 mail.info]
    j1OKMQte003194: Milter (dk-filter): to error state
    Feb 24 21:23:32 libra sendmail[3194]: [ID 801593 mail.error]
    j1OKMQte003194: Milter (dk-filter): init failed to open
    Feb 24 21:23:32 libra sendmail[3194]: [ID 801593 mail.info]
    j1OKMQte003194: Milter (dk-filter): to error state
    Feb 24 21:23:32 libra sendmail[3194]: [ID 801593 mail.info]
    j1OKMQte003194: Milter: connect to filters
    Feb 24 21:23:35 libra sendmail[3194]: [ID 801593 mail.info]
    j1OKMQte003194: from=<Brostrom.Carl@bcg.com>, size=8431,
    class=0, nrcpts=1,
    msgid=<10DE81BD6D18144AA877EDA639BB15462793AE@stkemail01.bcg.com>,
    proto=SMTP, daemon=MTA-v4, relay=mail98.messagelabs.com
    [216.82.244.147]
    Feb 24 21:23:35 libra sendmail[3194]: [ID 801593 mail.info]
    j1OKMQte003194: Milter accept: message
    Feb 24 21:23:35 libra sendmail[3223]: [ID 801593 mail.info]
    j1OKMQte003194: to=<lennart.asander@vattenfall.com>,
    delay=00:00:01, xdelay=00:00:00, mailer=relay, pri=128431,
    relay=pegasus.vattenfall.se. [151.156.192.2], dsn=2.0.0,
    stat=Sent (j1OKNZ9V010792 Message accepted for delivery)

     
  • Fredrik Pettai

    Fredrik Pettai - 2005-02-28

    Logged In: YES
    user_id=370342

    Hmmm... maybe this a side effect of using select() instead
    of poll().
    I will recompile sendmail and start the tests again...

    Re,
    /P

     
  • Anonymous - 2005-02-28

    Logged In: YES
    user_id=1048957

    The error appears to be something to do with the socket
    libmilter is using to listen for connections. I see this in
    the log every so often:

    Feb 27 03:03:21 medusa sm-mta[4633]: j1RB3Bvg004633: Milter
    (dk-filter): timeout before data read
    Feb 27 03:03:21 medusa sm-mta[4633]: j1RB3Bvg004633: Milter
    (dk-filter): to error state
    Feb 27 03:03:21 medusa sm-mta[4633]: j1RB3Bvg004633: Milter
    (dk-filter): init failed to open
    Feb 27 03:03:21 medusa sm-mta[4633]: j1RB3Bvg004633: Milter
    (dk-filter): to error state
    Feb 27 03:03:21 medusa dk-filter[8515]: Sendmail DomainKeys
    Filter: accept() returned invalid socket (Bad file
    descriptor), try again

    So the accept() in libmilter/listener.c is failing, claiming
    the listening socket is suddenly no good anymore. After
    this happens a fixed number of times in a row (MAX_FAILS_A,
    or 16), the filter will give up trying and terminate.

    If you enable the auto-restart feature ("-A"), the filter
    will restart itself when this happens, but that doesn't
    really fix the problem.

     
  • Fredrik Pettai

    Fredrik Pettai - 2005-02-28

    Logged In: YES
    user_id=370342

    I had to use -A for both dk-filter and sid-filter.
    Now that sid-filter don't seems to have any with stability
    anymore, so i removed -A . I thought the same for dk-filter
    but after some days it went down anyway. But no core-files
    this time.

    >So the accept() in libmilter/listener.c is failing, claiming
    >the listening socket is suddenly no good anymore. After
    >this happens a fixed number of times in a row (MAX_FAILS_A,
    >or 16), the filter will give up trying and terminate.

    Isn't this strange? Why aren't other milter-plugin (like
    sid-filter) experiencing the same thing?

    Are you using a socketfile or do you use a local port?
    I use a local port since i had problems with socketfiles
    which don't get deleted then the filter exits (perhaps due
    to abnormal exits). Then when the filter restarts, it
    complains about the socketfile and exits again... So -A
    wasn't that good to use in that configuration.

     
  • Anonymous - 2005-02-28

    Logged In: YES
    user_id=1048957

    I use a UNIX domain socket (file). This is on OpenBSD and
    you're on Solaris, so it's definitely not an operating
    system problem.

    Are you using USE_ARLIB for both filters?

     
  • Fredrik Pettai

    Fredrik Pettai - 2005-02-28

    Logged In: YES
    user_id=370342

    Yepp, i suppose so since i haven't change any configuration
    then compiling the filters. (I have a weak memory that you
    needed to changes a Makefile or m4-file to get native
    resolver support).
    libar.a gets compiled and installed.

     
  • Anonymous - 2005-02-28

    Logged In: YES
    user_id=1048957

    libdk doesn't build with USE_ARLIB by default. Please check
    because if you're not using USE_ARLIB in your builds, then
    we know the problem isn't in the libar code.

     
  • Fredrik Pettai

    Fredrik Pettai - 2005-02-28

    Logged In: YES
    user_id=370342

    dk-filter compiled with USE_ARLIB. Lets see if the error
    symptoms disappear...

     
  • Fredrik Pettai

    Fredrik Pettai - 2005-03-08
    • status: open --> closed
     
  • Fredrik Pettai

    Fredrik Pettai - 2005-03-08

    Logged In: YES
    user_id=370342

    Apparently, this also seems to be a bug related to native
    resolver on Solaris 9. With libar, this doesn't appear...
    Thanks for the help!

    Re,
    /P

     

Log in to post a comment.

Get latest updates about Open Source Projects, Conferences and News.

Sign up for the SourceForge newsletter:

JavaScript is required for this form.





No, thanks