<br>I got this message when a script was sending 14 emails, 2 mails failed at first try, but were finally delivered 27min later !<br><br>As you can see, emails send before and after didn't encounter any problems.<br>It looks like a race condition, but the server was not doing anything a that time !
<br>I retried to reproduce the problem, but without success ! <br>This is a Kolab 2.1 beta4<br><br>I suspect "ockers" to be garbage, because -1 is probably an unexpected error number !<br><br>Any idea<br><br><br>
=== /kolab/var/resmgr/resmgr.log<br><br>March 19 03:18:16 kolabmailboxfilter.php[8553]: Debug: Kolabmailboxfilter successfully completed<br>March
19 03:18:16 kolabmailboxfilter.php[8555]: Debug: Kolabmailboxfilter
starting up, sender=<a href="mailto:alain.spineux@asxnet.loc">alain.spineux@asxnet.loc</a>,
recipients=catchall.mydomain.loc@mydomain.<br>loc, client_address=<a href="http://127.0.0.1">127.0.0.1</a><br>March 19 03:18:17 kolabmailboxfilter.php[8555]: Debug: Kolabmailboxfilter successfully completed<br>March
19 03:18:17 kolabmailboxfilter.php[8557]: Debug: Kolabmailboxfilter
starting up, sender=<a href="mailto:alain.spineux@asxnet.loc">alain.spineux@asxnet.loc</a>,
recipients=catchall.mydomain.loc@mydomain.<br>loc, client_address=<a href="http://127.0.0.1">127.0.0.1</a><br>March
19 03:18:17 kolabmailboxfilter.php[8557]: Error: Failed to set
recipient <a href="mailto:catchall.mydomain.loc@mydomain.loc">catchall.mydomain.loc@mydomain.loc</a>: ockers, code=-1<br>March
19 03:18:17 kolabmailboxfilter.php[8560]: Debug: Kolabmailboxfilter
starting up, sender=<a href="mailto:alain.spineux@asxnet.loc">alain.spineux@asxnet.loc</a>,
recipients=catchall.mydomain.loc@mydomain.<br>loc, client_address=<a href="http://127.0.0.1">127.0.0.1</a><br>March
19 03:18:17 kolabmailboxfilter.php[8560]: Error: Failed to set
recipient <a href="mailto:catchall.mydomain.loc@mydomain.loc">catchall.mydomain.loc@mydomain.loc</a>: ockers, code=-1<br>March
19 03:18:18 kolabmailboxfilter.php[8561]: Debug: Kolabmailboxfilter
starting up, sender=<a href="mailto:alain.spineux@asxnet.loc">alain.spineux@asxnet.loc</a>,
recipients=catchall.mydomain.loc@mydomain.<br>loc, client_address=<a href="http://127.0.0.1">127.0.0.1</a><br>March 19 03:18:18 kolabmailboxfilter.php[8561]: Debug: Kolabmailboxfilter successfully completed<br><br><br><br>
Here is the postfig logs for one of the 2 mails <br><br><br>[root@fc6-eg ~]# egrep "20070319021808.663CB374CC|663CB374CC|270167FB8|8ACFB7FB7" /kolab/var/postfix/log/postfix.log<br>Mar 19 03:18:08 fc6-eg.asxnet.loc
<info> postfix/smtpd[8494]: 663CB374CC: client=localhost.localdomain[<a href="http://127.0.0.1">127.0.0.1</a>]<br>Mar 19 03:18:08 fc6-eg.asxnet.loc <info> postfix/cleanup[8499]: 663CB374CC: message-id=<<a href="mailto:20070319021808.663CB374CC@fc6-eg.asxnet.loc">
20070319021808.663CB374CC@fc6-eg.asxnet.loc</a>><br>Mar 19 03:18:08 fc6-eg.asxnet.loc <info> postfix/qmgr[7323]: 663CB374CC: from=<<a href="mailto:alain.spineux@asxnet.loc">alain.spineux@asxnet.loc</a>>, size=413, nrcpt=1 (queue active)
<br>Mar 19 03:18:10 fc6-eg.asxnet.loc <info> postfix/smtpd[8506]: 270167FB8: client=localhost.localdomain[<a href="http://127.0.0.1">127.0.0.1</a>]<br>Mar 19 03:18:10 fc6-eg.asxnet.loc <info> postfix/cleanup[8507]: 270167FB8: message-id=<
<a href="mailto:20070319021808.663CB374CC@fc6-eg.asxnet.loc">20070319021808.663CB374CC@fc6-eg.asxnet.loc</a>><br>Mar 19 03:18:10 fc6-eg.asxnet.loc <info> postfix/pipe[8504]: 663CB374CC: to=<<a href="mailto:catchall.mydomain.loc@mydomain.loc">
catchall.mydomain.loc@mydomain.loc</a>>, orig_to=<<a href="mailto:john@mydomain.loc">john@mydomain.loc</a>>, relay=kolabfilter, delay=2, status=sent (fc6-eg.asxnet.loc)<br>Mar 19 03:18:10 fc6-eg.asxnet.loc <info> postfix/qmgr[7323]: 663CB374CC: removed
<br>Mar 19 03:18:10 fc6-eg.asxnet.loc <info> postfix/qmgr[7323]: 270167FB8: from=<<a href="mailto:alain.spineux@asxnet.loc">alain.spineux@asxnet.loc</a>>, size=648, nrcpt=1 (queue active)<br>Mar 19 03:18:17 fc6-eg.asxnet.loc
<info> postfix/smtpd[8528]: 8ACFB7FB7: client=localhost.localdomain[<a href="http://127.0.0.1">127.0.0.1</a>]<br>Mar 19 03:18:17 fc6-eg.asxnet.loc <info> postfix/cleanup[8507]: 8ACFB7FB7: message-id=<<a href="mailto:20070319021808.663CB374CC@fc6-eg.asxnet.loc">
20070319021808.663CB374CC@fc6-eg.asxnet.loc</a>><br>Mar 19 03:18:17 fc6-eg.asxnet.loc <info> postfix/qmgr[7323]: 8ACFB7FB7: from=<<a href="mailto:alain.spineux@asxnet.loc">alain.spineux@asxnet.loc</a>>, size=1126, nrcpt=1 (queue active)
<br>Mar 19 03:18:17 fc6-eg.asxnet.loc <info> postfix/smtp[8516]: 270167FB8: to=<<a href="mailto:catchall.mydomain.loc@mydomain.loc">catchall.mydomain.loc@mydomain.loc</a>>, relay=127.0.0.1[<a href="http://127.0.0.1">
127.0.0.1</a>], delay=7, status=sent (250 2.6.0 Ok, id=07267-02-4, from MTA([<a href="http://127.0.0.1">127.0.0.1</a>]:10026): 250 Ok: queued as 8ACFB7FB7)<br>Mar 19 03:18:17 fc6-eg.asxnet.loc <info> postfix/qmgr[7323]: 270167FB8: removed
<br>Mar 19 03:18:17 fc6-eg.asxnet.loc <info> postfix/pipe[8536]: 8ACFB7FB7: to=<<a href="mailto:catchall.mydomain.loc@mydomain.loc">catchall.mydomain.loc@mydomain.loc</a>>, relay=kolabmailboxfilter, delay=0, status=deferred (temporary failure. Command output: Failed to set recipient: ockers, code -1 )
<br>Mar 19 03:45:35 fc6-eg.asxnet.loc <info> postfix/qmgr[7323]: 8ACFB7FB7: from=<<a href="mailto:alain.spineux@asxnet.loc">alain.spineux@asxnet.loc</a>>, size=1126, nrcpt=1 (queue active)<br>Mar 19 03:45:35 fc6-eg.asxnet.loc
<info> postfix/pipe[10997]: 8ACFB7FB7: to=<<a href="mailto:catchall.mydomain.loc@mydomain.loc">catchall.mydomain.loc@mydomain.loc</a>>, relay=kolabmailboxfilter, delay=1638, status=sent (fc6-eg.asxnet.loc)<br>
Mar 19 03:45:35 fc6-eg.asxnet.loc <info> postfix/qmgr[7323]: 8ACFB7FB7: removed<br><br><br><br><br><br>/kolab/var/kolab/php/kolabfilter/kolabmailtransport.php<br><br> function start($sender,$recips) {<br> $this->createTransport();
<br> $myclass = get_class($this->transport);<br> $this->got_newline = true;<br><br> if (!$this->transport) {<br> return new PEAR_Error('Failed to connect to $myclass: ' . $error->getMessage(), 421);
<br> }<br> if (PEAR::isError($error = $this->transport->connect())) {<br> return new PEAR_Error('Failed to connect to $myclass: ' . $error->getMessage(), 421);<br> }<br><br> if (PEAR::isError($error = $this->transport->mailFrom($sender))) {
<br> $resp = $this->transport->getResponse();<br> return new PEAR_Error('Failed to set sender: ' . $resp[1], $resp[0] );<br> }<br><br> if( !is_array( $recips ) ) $recips = array($recips);<br>
<br> $reciperrors = array();<br> foreach( $recips as $recip ) {<br> if (PEAR::isError($error = $this->transport->rcptTo($recip))) {<br> $resp = $this->transport->getResponse();<br> $msg = "Failed to set recipient $recip: " .$resp[1]. ", code=".$resp[0];
<br> myLog($msg, RM_LOG_ERROR);<br> $reciperrors[] = new PEAR_Error('Failed to set recipient: '.$resp[1], $resp[0]);<br> }<br> }<br> if( count($reciperrors) == count($recips) ) {<br> // OK, all failed, just give up
<br> if( count($reciperrors) == 1 ) {<br> // Only one failure, just return that<br> return $reciperrors[0];<br> }<br> // Multiple errors<br> return $this->createErrorObject( $reciperrors, 'Delivery to all recipients failed' );
<br> }<br><br> if (PEAR::isError($error = $this->transport->_put('DATA'))) {<br> return $error;<br> }<br> if (PEAR::isError($error = $this->transport->_parseResponse(354))) {<br> return $error;
<br> }<br> if( !empty($reciperrors) ) {<br> return $this->createErrorObject( $reciperrors, 'Delivery to some recipients failed' );<br> }<br> return true;<br> }<br><br><br>-- <br>--<br>Alain Spineux
<br>aspineux gmail com<br>May the sources be with you<br><br>