kolabmailboxfilter.php[8560]: Error: Failed to set recipient ...

[Alain Spineux]

I got this message when a script was sending 14 emails, 2 mails failed at
first try, but were finally delivered 27min later !

As you can see, emails send before and after didn't encounter any problems.
It looks like a race condition, but the server was not doing anything a that
time !
I retried to reproduce the problem, but without success !
This is a Kolab 2.1 beta4

I suspect "ockers"  to be garbage, because -1 is probably an unexpected
error number !

Any idea


=== /kolab/var/resmgr/resmgr.log

March 19 03:18:16 kolabmailboxfilter.php[8553]: Debug: Kolabmailboxfilter
successfully completed
March 19 03:18:16 kolabmailboxfilter.php[8555]: Debug: Kolabmailboxfilter
starting up, sender=alain.spineux at asxnet.loc, recipients=
catchall.mydomain.loc at mydomain.
loc, client_address=127.0.0.1
March 19 03:18:17 kolabmailboxfilter.php[8555]: Debug: Kolabmailboxfilter
successfully completed
March 19 03:18:17 kolabmailboxfilter.php[8557]: Debug: Kolabmailboxfilter
starting up, sender=alain.spineux at asxnet.loc, recipients=
catchall.mydomain.loc at mydomain.
loc, client_address=127.0.0.1
March 19 03:18:17 kolabmailboxfilter.php[8557]: Error: Failed to set
recipient catchall.mydomain.loc at mydomain.loc: ockers, code=-1
March 19 03:18:17 kolabmailboxfilter.php[8560]: Debug: Kolabmailboxfilter
starting up, sender=alain.spineux at asxnet.loc, recipients=
catchall.mydomain.loc at mydomain.
loc, client_address=127.0.0.1
March 19 03:18:17 kolabmailboxfilter.php[8560]: Error: Failed to set
recipient catchall.mydomain.loc at mydomain.loc: ockers, code=-1
March 19 03:18:18 kolabmailboxfilter.php[8561]: Debug: Kolabmailboxfilter
starting up, sender=alain.spineux at asxnet.loc, recipients=
catchall.mydomain.loc at mydomain.
loc, client_address=127.0.0.1
March 19 03:18:18 kolabmailboxfilter.php[8561]: Debug: Kolabmailboxfilter
successfully completed



Here is the postfig logs for one of the 2 mails


[root at fc6-eg ~]# egrep "
20070319021808.663CB374CC|663CB374CC|270167FB8|8ACFB7FB7
"  /kolab/var/postfix/log/postfix.log
Mar 19 03:18:08 fc6-eg.asxnet.loc <info> postfix/smtpd[8494]: 663CB374CC:
client=localhost.localdomain[127.0.0.1]
Mar 19 03:18:08 fc6-eg.asxnet.loc <info> postfix/cleanup[8499]: 663CB374CC:
message-id=<20070319021808.663CB374CC at fc6-eg.asxnet.loc>
Mar 19 03:18:08 fc6-eg.asxnet.loc <info> postfix/qmgr[7323]: 663CB374CC:
from=<alain.spineux at asxnet.loc>, size=413, nrcpt=1 (queue active)
Mar 19 03:18:10 fc6-eg.asxnet.loc <info> postfix/smtpd[8506]: 270167FB8:
client=localhost.localdomain[127.0.0.1]
Mar 19 03:18:10 fc6-eg.asxnet.loc <info> postfix/cleanup[8507]: 270167FB8:
message-id=<20070319021808.663CB374CC at fc6-eg.asxnet.loc>
Mar 19 03:18:10 fc6-eg.asxnet.loc <info> postfix/pipe[8504]: 663CB374CC:
to=<catchall.mydomain.loc at mydomain.loc>, orig_to=<john at mydomain.loc>,
relay=kolabfilter, delay=2, status=sent (fc6-eg.asxnet.loc)
Mar 19 03:18:10 fc6-eg.asxnet.loc <info> postfix/qmgr[7323]: 663CB374CC:
removed
Mar 19 03:18:10 fc6-eg.asxnet.loc <info> postfix/qmgr[7323]: 270167FB8:
from=<alain.spineux at asxnet.loc>, size=648, nrcpt=1 (queue active)
Mar 19 03:18:17 fc6-eg.asxnet.loc <info> postfix/smtpd[8528]: 8ACFB7FB7:
client=localhost.localdomain[127.0.0.1]
Mar 19 03:18:17 fc6-eg.asxnet.loc <info> postfix/cleanup[8507]: 8ACFB7FB7:
message-id=<20070319021808.663CB374CC at fc6-eg.asxnet.loc>
Mar 19 03:18:17 fc6-eg.asxnet.loc <info> postfix/qmgr[7323]: 8ACFB7FB7:
from=<alain.spineux at asxnet.loc>, size=1126, nrcpt=1 (queue active)
Mar 19 03:18:17 fc6-eg.asxnet.loc <info> postfix/smtp[8516]: 270167FB8: to=<
catchall.mydomain.loc at mydomain.loc>, relay=127.0.0.1[127.0.0.1], delay=7,
status=sent (250 2.6.0 Ok, id=07267-02-4, from MTA([127.0.0.1]:10026): 250
Ok: queued as 8ACFB7FB7)
Mar 19 03:18:17 fc6-eg.asxnet.loc <info> postfix/qmgr[7323]: 270167FB8:
removed
Mar 19 03:18:17 fc6-eg.asxnet.loc <info> postfix/pipe[8536]: 8ACFB7FB7: to=<
catchall.mydomain.loc at mydomain.loc>, relay=kolabmailboxfilter, delay=0,
status=deferred (temporary failure. Command output: Failed to set recipient:
ockers, code -1 )
Mar 19 03:45:35 fc6-eg.asxnet.loc <info> postfix/qmgr[7323]: 8ACFB7FB7:
from=<alain.spineux at asxnet.loc>, size=1126, nrcpt=1 (queue active)
Mar 19 03:45:35 fc6-eg.asxnet.loc <info> postfix/pipe[10997]: 8ACFB7FB7:
to=<catchall.mydomain.loc at mydomain.loc>, relay=kolabmailboxfilter,
delay=1638, status=sent (fc6-eg.asxnet.loc)
Mar 19 03:45:35 fc6-eg.asxnet.loc <info> postfix/qmgr[7323]: 8ACFB7FB7:
removed





/kolab/var/kolab/php/kolabfilter/kolabmailtransport.php

  function start($sender,$recips) {
    $this->createTransport();
    $myclass = get_class($this->transport);
    $this->got_newline = true;

    if (!$this->transport) {
      return new PEAR_Error('Failed to connect to $myclass: ' .
$error->getMessage(), 421);
    }
    if (PEAR::isError($error = $this->transport->connect())) {
      return new PEAR_Error('Failed to connect to $myclass: ' .
$error->getMessage(), 421);
    }

    if (PEAR::isError($error = $this->transport->mailFrom($sender))) {
      $resp = $this->transport->getResponse();
      return new PEAR_Error('Failed to set sender: ' . $resp[1], $resp[0] );
    }

    if( !is_array( $recips ) ) $recips = array($recips);

    $reciperrors = array();
    foreach( $recips as $recip ) {
      if (PEAR::isError($error = $this->transport->rcptTo($recip))) {
        $resp = $this->transport->getResponse();
        $msg = "Failed to set recipient $recip: " .$resp[1]. ",
code=".$resp[0];
        myLog($msg, RM_LOG_ERROR);
        $reciperrors[] = new PEAR_Error('Failed to set recipient:
'.$resp[1], $resp[0]);
      }
    }
    if( count($reciperrors) == count($recips) ) {
      // OK, all failed, just give up
      if( count($reciperrors) == 1 ) {
        // Only one failure, just return that
        return $reciperrors[0];
      }
      // Multiple errors
      return $this->createErrorObject( $reciperrors, 'Delivery to all
recipients failed' );
    }

    if (PEAR::isError($error = $this->transport->_put('DATA'))) {
      return $error;
    }
    if (PEAR::isError($error = $this->transport->_parseResponse(354))) {
      return $error;
    }
    if( !empty($reciperrors) ) {
      return $this->createErrorObject( $reciperrors, 'Delivery to some
recipients failed' );
    }
    return true;
  }


-- 
--
Alain Spineux
aspineux gmail com
May the sources be with you
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.kolab.org/pipermail/users/attachments/20070319/8c4876d2/attachment.html>