I have found a problem with receiving mails from (until now) one domain.
With Postfix only everything is fine.If i use assp in front of the postfix server the sending mail server (mo-p00-ob.rzone.de) terminates the communication with a QUIT after the HELO-process.
mo-p00-ob.rzone.de <---> mail.fiwi.at:25 (assp) <---> mail.fiwi.at:125 (postfix)
I have attached the Debug-Log from assp (1256132304.dbg), the logfile from assp (maillog.txt) and the logfile from postfix (mail.log).
As an example i have also attached the correct communication (which was really the same server and the same mail!!) in working_postfix.log which i received shortly after removing assp from the configuration. I am using the actual assp version (Version 2.0.1(RC 0.5.02)) which i downloaded today.
So i am looking forward for your help, thanks in advance, pt PS: I am able to repeat this problem. It's not just a one time event!
Oct-21-09 15:38:23 [Worker_2] <addfh >Oct-21-09 15:38:23 [Worker_2] <addfh >Oct-21-09 15:38:23 [Worker_2] <Connected: IO::Socket::INET=GLOB(0x9641790) -- >IO::Socket::INET=GLOB(0x8bcc830) >Oct-21-09 15:38:23 [Worker_2] <* connect ip=81.169.146.162 relay=<0> * >Oct-21-09 15:38:23 [Worker_2] Connected: 81.169.146.162:36018 > >85.126.114.2:25 > 85.126.114.2:125 , 9-10 Oct-21-09 15:38:23 [Worker_2] <IO::Socket::INET=GLOB(0x9641790) HASH(0x8bd0fa0) l=0 >Oct-21-09 15:38:23 [Worker_2] <IO::Socket::INET=GLOB(0x8bcc830) >HASH(0x8bc8f30) l=0 >Oct-21-09 15:38:23 [Worker_2] <SMTPTraffic - read OK >Oct-21-09 15:38:23 [Worker_2] <SMTPTraffic - process read >Oct-21-09 15:38:23 [Worker_2] <doing line <220 mail.fiwi.at ESMTP >Postfix[CR][LF] > >Oct-21-09 15:38:23 [Worker_2] <reply >Oct-21-09 15:38:23 [Worker_2] <reply : 220 mail.fiwi.at ESMTP Postfix[CR][LF] >Oct-21-09 15:38:23 [Worker_2] <sq: IO::Socket::INET=GLOB(0x8bcc830) l=0 >Oct-21-09 15:38:23 [Worker_2] <noop to server 1 >Oct-21-09 15:38:23 [Worker_2] <sq: IO::Socket::INET=GLOB(0x9641790) l=32 >Oct-21-09 15:38:23 [Worker_2] SC-Time Worker_2: 0.000747919082641602 Oct-21-09 15:38:23 [Worker_2] <IO::Socket::INET=GLOB(0x8bcc830) HASH(0x8bc8f30) l=0 >Oct-21-09 15:38:23 [Worker_2] <IO::Socket::INET=GLOB(0x9641790) >HASH(0x8bd0fa0) l=32 >Oct-21-09 15:38:23 [Worker_2] <wrote: IO::Socket::INET=GLOB(0x9641790) >(32)<220 mail.fiwi.at ESMTP Postfix[CR][LF] > >Oct-21-09 15:38:23 [Worker_2] <SMTPTraffic - read OK >Oct-21-09 15:38:23 [Worker_2] <SMTPTraffic - process read >Oct-21-09 15:38:23 [Worker_2] <doing line <EHLO mo-p00-ob.rzone.de[CR][LF] > >Oct-21-09 15:38:23 [Worker_2] <getline >Oct-21-09 15:38:23 [Worker_2] <gl: <EHLO mo-p00-ob.rzone.de[CR][LF] > >Oct-21-09 15:38:23 [Worker_2] <headerWrap >Oct-21-09 15:38:23 [Worker_2] <sq: IO::Socket::INET=GLOB(0x8bcc830) l=25 >Oct-21-09 15:38:23 [Worker_2] 81.169.146.162 SC-Time Worker_2: >0.0255899429321289 Oct-21-09 15:38:23 [Worker_2] <IO::Socket::INET=GLOB(0x8bcc830) HASH(0x8bc8f30) l=25 >Oct-21-09 15:38:23 [Worker_2] <wrote: IO::Socket::INET=GLOB(0x8bcc830) >(25)<EHLO mo-p00-ob.rzone.de[CR][LF] > >Oct-21-09 15:38:23 [Worker_2] <SMTPTraffic - read OK >Oct-21-09 15:38:23 [Worker_2] <SMTPTraffic - process read >Oct-21-09 15:38:23 [Worker_2] <doing line <250-mail.fiwi.at[CR][LF] > >Oct-21-09 15:38:23 [Worker_2] <reply >Oct-21-09 15:38:23 [Worker_2] <reply : 250-mail.fiwi.at[CR][LF] >Oct-21-09 15:38:23 [Worker_2] <faked 250-STARTTLS >Oct-21-09 15:38:23 [Worker_2] 81.169.146.162 info: faked '250-STARTTLS ready' >for 85.126.114.2 Oct-21-09 15:38:23 [Worker_2] <sq: IO::Socket::INET=GLOB(0x9641790) l=33 >Oct-21-09 15:38:23 [Worker_2] <doing line <250-PIPELINING[CR][LF] > >Oct-21-09 15:38:23 [Worker_2] <reply >Oct-21-09 15:38:23 [Worker_2] <reply : 250-PIPELINING[CR][LF] >Oct-21-09 15:38:23 [Worker_2] <250-sequenz - from server: >>250-PIPELINING[CR][LF] < >Oct-21-09 15:38:23 [Worker_2] <250-sequenz - to client: >< >Oct-21-09 15:38:23 [Worker_2] <doing line <250-SIZE 504800000[CR][LF] > >Oct-21-09 15:38:23 [Worker_2] <reply >Oct-21-09 15:38:23 [Worker_2] <reply : 250-SIZE 504800000[CR][LF] >Oct-21-09 15:38:23 [Worker_2] <sq: IO::Socket::INET=GLOB(0x8bcc830) l=0 >Oct-21-09 15:38:23 [Worker_2] <noop to server 1 >Oct-21-09 15:38:23 [Worker_2] <sq: IO::Socket::INET=GLOB(0x9641790) l=20 >Oct-21-09 15:38:23 [Worker_2] <doing line <250-ETRN[CR][LF] > >Oct-21-09 15:38:23 [Worker_2] <reply >Oct-21-09 15:38:23 [Worker_2] <reply : 250-ETRN[CR][LF] >Oct-21-09 15:38:23 [Worker_2] <sq: IO::Socket::INET=GLOB(0x9641790) l=10 >Oct-21-09 15:38:23 [Worker_2] <doing line <250-STARTTLS[CR][LF] > >Oct-21-09 15:38:23 [Worker_2] <reply >Oct-21-09 15:38:23 [Worker_2] <reply : 250-STARTTLS[CR][LF] >Oct-21-09 15:38:23 [Worker_2] <doing line <250-AUTH PLAIN LOGIN[CR][LF] > >Oct-21-09 15:38:23 [Worker_2] <reply >Oct-21-09 15:38:23 [Worker_2] <reply : 250-AUTH PLAIN LOGIN[CR][LF] >Oct-21-09 15:38:23 [Worker_2] <sq: IO::Socket::INET=GLOB(0x9641790) l=22 >Oct-21-09 15:38:23 [Worker_2] <doing line <250-AUTH=PLAIN LOGIN[CR][LF] > >Oct-21-09 15:38:23 [Worker_2] <reply >Oct-21-09 15:38:23 [Worker_2] <reply : 250-AUTH=PLAIN LOGIN[CR][LF] >Oct-21-09 15:38:23 [Worker_2] <sq: IO::Socket::INET=GLOB(0x9641790) l=22 >Oct-21-09 15:38:23 [Worker_2] <doing line <250-ENHANCEDSTATUSCODES[CR][LF] > >Oct-21-09 15:38:23 [Worker_2] <reply >Oct-21-09 15:38:23 [Worker_2] <reply : 250-ENHANCEDSTATUSCODES[CR][LF] >Oct-21-09 15:38:23 [Worker_2] <sq: IO::Socket::INET=GLOB(0x9641790) l=25 >Oct-21-09 15:38:23 [Worker_2] <doing line <250-8BITMIME[CR][LF] > >Oct-21-09 15:38:23 [Worker_2] <reply >Oct-21-09 15:38:23 [Worker_2] <reply : 250-8BITMIME[CR][LF] >Oct-21-09 15:38:23 [Worker_2] <sq: IO::Socket::INET=GLOB(0x9641790) l=14 >Oct-21-09 15:38:23 [Worker_2] <doing line <250 DSN[CR][LF] > >Oct-21-09 15:38:23 [Worker_2] <reply >Oct-21-09 15:38:23 [Worker_2] <reply : 250 DSN[CR][LF] >Oct-21-09 15:38:23 [Worker_2] <sq: IO::Socket::INET=GLOB(0x9641790) l=9 >Oct-21-09 15:38:23 [Worker_2] SC-Time Worker_2: 0.0119800567626953 Oct-21-09 15:38:23 [Worker_2] <IO::Socket::INET=GLOB(0x9641790) HASH(0x8bd0fa0) l=155 >Oct-21-09 15:38:23 [Worker_2] <wrote: IO::Socket::INET=GLOB(0x9641790) >(155)<250-mail.fiwi.at[CR][CR][LF] 250-STARTTLS[CR][LF] 250-SIZE 504800000[CR][LF] 250-ETRN[CR][LF] 250-AUTH PLAIN LOGIN[CR][LF] 250-AUTH=PLAIN LOGIN[CR][LF] 250-ENHANCEDSTATUSCODES[CR][LF] 250-8BITMIME[CR][LF] 250 DSN[CR][LF] > >Oct-21-09 15:38:23 [Worker_2] <IO::Socket::INET=GLOB(0x8bcc830) >HASH(0x8bc8f30) l=0 >Oct-21-09 15:38:23 [Worker_2] <SMTPTraffic - read OK >Oct-21-09 15:38:23 [Worker_2] <SMTPTraffic - process read >Oct-21-09 15:38:23 [Worker_2] <doing line <QUIT[CR][LF] > >Oct-21-09 15:38:23 [Worker_2] <getline >Oct-21-09 15:38:23 [Worker_2] <gl: <QUIT[CR][LF] > >Oct-21-09 15:38:23 [Worker_2] <sq: IO::Socket::INET=GLOB(0x8bcc830) l=6 >Oct-21-09 15:38:23 [Worker_2] 81.169.146.162 SC-Time Worker_2: >0.000629901885986328 Oct-21-09 15:38:23 [Worker_2] <IO::Socket::INET=GLOB(0x8bcc830) HASH(0x8bc8f30) l=6 >Oct-21-09 15:38:23 [Worker_2] <wrote: IO::Socket::INET=GLOB(0x8bcc830) >(6)<QUIT[CR][LF] > >Oct-21-09 15:38:23 [Worker_2] <SMTPTraffic - no more data - >Oct-21-09 15:38:23 [Worker_2] 81.169.146.162 info: no (more) data readable >from 81.169.146.162 (connection closed by peer) - last command was 'QUIT' Oct-21-09 15:38:23 [Worker_2] 81.169.146.162 SC-Time Worker_2: 0.000474929809570312 Oct-21-09 15:39:22 [Worker_2] <addfh >Oct-21-09 15:39:22 [Worker_2] <addfh >Oct-21-09 15:39:22 [Worker_2] <Connected: IO::Socket::INET=GLOB(0x8bcc210) -- >IO::Socket::INET=GLOB(0x9620230) >Oct-21-09 15:39:22 [Worker_2] <* connect ip=81.169.146.162 relay=<0> * >Oct-21-09 15:39:22 [Worker_2] Connected: 81.169.146.162:38308 > >85.126.114.2:25 > 85.126.114.2:125 , 10-11 Oct-21-09 15:39:22 [Worker_2] <IO::Socket::INET=GLOB(0x9620230) HASH(0x93f0ba0) l=0 >Oct-21-09 15:39:22 [Worker_2] <IO::Socket::INET=GLOB(0x8bcc210) >HASH(0x9641530) l=0 >Oct-21-09 15:39:22 [Worker_2] <SMTPTraffic - read OK >Oct-21-09 15:39:22 [Worker_2] <SMTPTraffic - process read >Oct-21-09 15:39:22 [Worker_2] <doing line <220 mail.fiwi.at ESMTP >Postfix[CR][LF] > >Oct-21-09 15:39:22 [Worker_2] <reply >Oct-21-09 15:39:22 [Worker_2] <reply : 220 mail.fiwi.at ESMTP Postfix[CR][LF] >Oct-21-09 15:39:22 [Worker_2] <sq: IO::Socket::INET=GLOB(0x9620230) l=0 >Oct-21-09 15:39:22 [Worker_2] <noop to server 1 >Oct-21-09 15:39:22 [Worker_2] <sq: IO::Socket::INET=GLOB(0x8bcc210) l=32 >Oct-21-09 15:39:22 [Worker_2] SC-Time Worker_2: 0.00076603889465332 Oct-21-09 15:39:22 [Worker_2] <IO::Socket::INET=GLOB(0x9620230) HASH(0x93f0ba0) l=0 >Oct-21-09 15:39:22 [Worker_2] <IO::Socket::INET=GLOB(0x8bcc210) >HASH(0x9641530) l=32 >Oct-21-09 15:39:22 [Worker_2] <wrote: IO::Socket::INET=GLOB(0x8bcc210) >(32)<220 mail.fiwi.at ESMTP Postfix[CR][LF] > >Oct-21-09 15:39:22 [Worker_2] <SMTPTraffic - read OK >Oct-21-09 15:39:22 [Worker_2] <SMTPTraffic - process read >Oct-21-09 15:39:22 [Worker_2] <doing line <EHLO mo-p00-ob.rzone.de[CR][LF] > >Oct-21-09 15:39:22 [Worker_2] <getline >Oct-21-09 15:39:22 [Worker_2] <gl: <EHLO mo-p00-ob.rzone.de[CR][LF] > >Oct-21-09 15:39:22 [Worker_2] <headerWrap >Oct-21-09 15:39:22 [Worker_2] <sq: IO::Socket::INET=GLOB(0x9620230) l=25 >Oct-21-09 15:39:22 [Worker_2] 81.169.146.162 SC-Time Worker_2: >0.00338506698608398 Oct-21-09 15:39:22 [Worker_2] <IO::Socket::INET=GLOB(0x9620230) HASH(0x93f0ba0) l=25 >Oct-21-09 15:39:22 [Worker_2] <wrote: IO::Socket::INET=GLOB(0x9620230) >(25)<EHLO mo-p00-ob.rzone.de[CR][LF] > >Oct-21-09 15:39:22 [Worker_2] <SMTPTraffic - read OK >Oct-21-09 15:39:22 [Worker_2] <SMTPTraffic - process read >Oct-21-09 15:39:22 [Worker_2] <doing line <250-mail.fiwi.at[CR][LF] > >Oct-21-09 15:39:22 [Worker_2] <reply >Oct-21-09 15:39:22 [Worker_2] <reply : 250-mail.fiwi.at[CR][LF] >Oct-21-09 15:39:22 [Worker_2] <faked 250-STARTTLS >Oct-21-09 15:39:22 [Worker_2] 81.169.146.162 info: faked '250-STARTTLS ready' >for 85.126.114.2 Oct-21-09 15:39:22 [Worker_2] <sq: IO::Socket::INET=GLOB(0x8bcc210) l=33 >Oct-21-09 15:39:22 [Worker_2] <doing line <250-PIPELINING[CR][LF] > >Oct-21-09 15:39:22 [Worker_2] <reply >Oct-21-09 15:39:22 [Worker_2] <reply : 250-PIPELINING[CR][LF] >Oct-21-09 15:39:22 [Worker_2] <250-sequenz - from server: >>250-PIPELINING[CR][LF] < >Oct-21-09 15:39:22 [Worker_2] <250-sequenz - to client: >< >Oct-21-09 15:39:22 [Worker_2] <doing line <250-SIZE 504800000[CR][LF] > >Oct-21-09 15:39:22 [Worker_2] <reply >Oct-21-09 15:39:22 [Worker_2] <reply : 250-SIZE 504800000[CR][LF] >Oct-21-09 15:39:22 [Worker_2] <sq: IO::Socket::INET=GLOB(0x9620230) l=0 >Oct-21-09 15:39:22 [Worker_2] <noop to server 1 >Oct-21-09 15:39:22 [Worker_2] <sq: IO::Socket::INET=GLOB(0x8bcc210) l=20 >Oct-21-09 15:39:22 [Worker_2] <doing line <250-ETRN[CR][LF] > >Oct-21-09 15:39:22 [Worker_2] <reply >Oct-21-09 15:39:22 [Worker_2] <reply : 250-ETRN[CR][LF] >Oct-21-09 15:39:22 [Worker_2] <sq: IO::Socket::INET=GLOB(0x8bcc210) l=10 >Oct-21-09 15:39:22 [Worker_2] <doing line <250-STARTTLS[CR][LF] > >Oct-21-09 15:39:22 [Worker_2] <reply >Oct-21-09 15:39:22 [Worker_2] <reply : 250-STARTTLS[CR][LF] >Oct-21-09 15:39:22 [Worker_2] <doing line <250-AUTH PLAIN LOGIN[CR][LF] > >Oct-21-09 15:39:22 [Worker_2] <reply >Oct-21-09 15:39:22 [Worker_2] <reply : 250-AUTH PLAIN LOGIN[CR][LF] >Oct-21-09 15:39:22 [Worker_2] <sq: IO::Socket::INET=GLOB(0x8bcc210) l=22 >Oct-21-09 15:39:22 [Worker_2] <doing line <250-AUTH=PLAIN LOGIN[CR][LF] > >Oct-21-09 15:39:22 [Worker_2] <reply >Oct-21-09 15:39:22 [Worker_2] <reply : 250-AUTH=PLAIN LOGIN[CR][LF] >Oct-21-09 15:39:22 [Worker_2] <sq: IO::Socket::INET=GLOB(0x8bcc210) l=22 >Oct-21-09 15:39:22 [Worker_2] <doing line <250-ENHANCEDSTATUSCODES[CR][LF] > >Oct-21-09 15:39:22 [Worker_2] <reply >Oct-21-09 15:39:22 [Worker_2] <reply : 250-ENHANCEDSTATUSCODES[CR][LF] >Oct-21-09 15:39:22 [Worker_2] <sq: IO::Socket::INET=GLOB(0x8bcc210) l=25 >Oct-21-09 15:39:22 [Worker_2] <doing line <250-8BITMIME[CR][LF] > >Oct-21-09 15:39:22 [Worker_2] <reply >Oct-21-09 15:39:22 [Worker_2] <reply : 250-8BITMIME[CR][LF] >Oct-21-09 15:39:22 [Worker_2] <sq: IO::Socket::INET=GLOB(0x8bcc210) l=14 >Oct-21-09 15:39:22 [Worker_2] <doing line <250 DSN[CR][LF] > >Oct-21-09 15:39:22 [Worker_2] <reply >Oct-21-09 15:39:22 [Worker_2] <reply : 250 DSN[CR][LF] >Oct-21-09 15:39:22 [Worker_2] <sq: IO::Socket::INET=GLOB(0x8bcc210) l=9 >Oct-21-09 15:39:22 [Worker_2] SC-Time Worker_2: 0.00324201583862305 Oct-21-09 15:39:22 [Worker_2] <IO::Socket::INET=GLOB(0x9620230) HASH(0x93f0ba0) l=0 >Oct-21-09 15:39:22 [Worker_2] <IO::Socket::INET=GLOB(0x8bcc210) >HASH(0x9641530) l=155 >Oct-21-09 15:39:22 [Worker_2] <wrote: IO::Socket::INET=GLOB(0x8bcc210) >(155)<250-mail.fiwi.at[CR][CR][LF] 250-STARTTLS[CR][LF] 250-SIZE 504800000[CR][LF] 250-ETRN[CR][LF] 250-AUTH PLAIN LOGIN[CR][LF] 250-AUTH=PLAIN LOGIN[CR][LF] 250-ENHANCEDSTATUSCODES[CR][LF] 250-8BITMIME[CR][LF] 250 DSN[CR][LF] > >Oct-21-09 15:39:22 [Worker_2] <SMTPTraffic - read OK >Oct-21-09 15:39:22 [Worker_2] <SMTPTraffic - process read >Oct-21-09 15:39:22 [Worker_2] <doing line <QUIT[CR][LF] > >Oct-21-09 15:39:22 [Worker_2] <getline >Oct-21-09 15:39:22 [Worker_2] <gl: <QUIT[CR][LF] > >Oct-21-09 15:39:22 [Worker_2] <sq: IO::Socket::INET=GLOB(0x9620230) l=6 >Oct-21-09 15:39:22 [Worker_2] 81.169.146.162 SC-Time Worker_2: >0.000609159469604492 Oct-21-09 15:39:22 [Worker_2] <IO::Socket::INET=GLOB(0x9620230) HASH(0x93f0ba0) l=6 >Oct-21-09 15:39:22 [Worker_2] <wrote: IO::Socket::INET=GLOB(0x9620230) >(6)<QUIT[CR][LF] > >Oct-21-09 15:39:22 [Worker_2] <SMTPTraffic - no more data - >Oct-21-09 15:39:22 [Worker_2] 81.169.146.162 info: no (more) data readable >from 81.169.146.162 (connection closed by peer) - last command was 'QUIT' Oct-21-09 15:39:22 [Worker_2] 81.169.146.162 SC-Time Worker_2: 0.000463962554931641 Oct-21-09 15:46:27 [Worker_2] <addfh >Oct-21-09 15:46:27 [Worker_2] <addfh >Oct-21-09 15:46:27 [Worker_2] <Connected: IO::Socket::INET=GLOB(0x963e450) -- >IO::Socket::INET=GLOB(0x9640fe0) >Oct-21-09 15:46:27 [Worker_2] <* connect ip=81.169.146.161 relay=<0> * >Oct-21-09 15:46:27 [Worker_2] Connected: 81.169.146.161:56387 > >85.126.114.2:25 > 85.126.114.2:125 , 10-11 Oct-21-09 15:46:27 [Worker_2] <IO::Socket::INET=GLOB(0x9640fe0) HASH(0x9652ed0) l=0 >Oct-21-09 15:46:27 [Worker_2] <IO::Socket::INET=GLOB(0x963e450) >HASH(0x95f58e0) l=0 >Oct-21-09 15:46:27 [Worker_2] <SMTPTraffic - read OK >Oct-21-09 15:46:27 [Worker_2] <SMTPTraffic - process read >Oct-21-09 15:46:27 [Worker_2] <doing line <220 mail.fiwi.at ESMTP >Postfix[CR][LF] > >Oct-21-09 15:46:27 [Worker_2] <reply >Oct-21-09 15:46:27 [Worker_2] <reply : 220 mail.fiwi.at ESMTP Postfix[CR][LF] >Oct-21-09 15:46:27 [Worker_2] <sq: IO::Socket::INET=GLOB(0x9640fe0) l=0 >Oct-21-09 15:46:27 [Worker_2] <noop to server 1 >Oct-21-09 15:46:27 [Worker_2] <sq: IO::Socket::INET=GLOB(0x963e450) l=32 >Oct-21-09 15:46:27 [Worker_2] SC-Time Worker_2: 0.000761032104492188 Oct-21-09 15:46:27 [Worker_2] <IO::Socket::INET=GLOB(0x9640fe0) HASH(0x9652ed0) l=0 >Oct-21-09 15:46:27 [Worker_2] <IO::Socket::INET=GLOB(0x963e450) >HASH(0x95f58e0) l=32 >Oct-21-09 15:46:27 [Worker_2] <wrote: IO::Socket::INET=GLOB(0x963e450) >(32)<220 mail.fiwi.at ESMTP Postfix[CR][LF] > >Oct-21-09 15:46:27 [Worker_2] <SMTPTraffic - read OK >Oct-21-09 15:46:27 [Worker_2] <SMTPTraffic - process read >Oct-21-09 15:46:27 [Worker_2] <doing line <EHLO mo-p00-ob.rzone.de[CR][LF] > >Oct-21-09 15:46:27 [Worker_2] <getline >Oct-21-09 15:46:27 [Worker_2] <gl: <EHLO mo-p00-ob.rzone.de[CR][LF] > >Oct-21-09 15:46:27 [Worker_2] <headerWrap >Oct-21-09 15:46:27 [Worker_2] <sq: IO::Socket::INET=GLOB(0x9640fe0) l=25 >Oct-21-09 15:46:27 [Worker_2] 81.169.146.161 SC-Time Worker_2: >0.00334405899047852 Oct-21-09 15:46:27 [Worker_2] <IO::Socket::INET=GLOB(0x9640fe0) HASH(0x9652ed0) l=25 >Oct-21-09 15:46:27 [Worker_2] <wrote: IO::Socket::INET=GLOB(0x9640fe0) >(25)<EHLO mo-p00-ob.rzone.de[CR][LF] > >Oct-21-09 15:46:27 [Worker_2] <SMTPTraffic - read OK >Oct-21-09 15:46:27 [Worker_2] <SMTPTraffic - process read >Oct-21-09 15:46:27 [Worker_2] <doing line <250-mail.fiwi.at[CR][LF] > >Oct-21-09 15:46:27 [Worker_2] <reply >Oct-21-09 15:46:27 [Worker_2] <reply : 250-mail.fiwi.at[CR][LF] >Oct-21-09 15:46:27 [Worker_2] <faked 250-STARTTLS >Oct-21-09 15:46:27 [Worker_2] 81.169.146.161 info: faked '250-STARTTLS ready' >for 85.126.114.2 Oct-21-09 15:46:27 [Worker_2] <sq: IO::Socket::INET=GLOB(0x963e450) l=33 >Oct-21-09 15:46:27 [Worker_2] <doing line <250-PIPELINING[CR][LF] > >Oct-21-09 15:46:27 [Worker_2] <reply >Oct-21-09 15:46:27 [Worker_2] <reply : 250-PIPELINING[CR][LF] >Oct-21-09 15:46:27 [Worker_2] <250-sequenz - from server: >>250-PIPELINING[CR][LF] < >Oct-21-09 15:46:27 [Worker_2] <250-sequenz - to client: >< >Oct-21-09 15:46:27 [Worker_2] <doing line <250-SIZE 504800000[CR][LF] > >Oct-21-09 15:46:27 [Worker_2] <reply >Oct-21-09 15:46:27 [Worker_2] <reply : 250-SIZE 504800000[CR][LF] >Oct-21-09 15:46:27 [Worker_2] <sq: IO::Socket::INET=GLOB(0x9640fe0) l=0 >Oct-21-09 15:46:27 [Worker_2] <noop to server 1 >Oct-21-09 15:46:27 [Worker_2] <sq: IO::Socket::INET=GLOB(0x963e450) l=20 >Oct-21-09 15:46:27 [Worker_2] <doing line <250-ETRN[CR][LF] > >Oct-21-09 15:46:27 [Worker_2] <reply >Oct-21-09 15:46:27 [Worker_2] <reply : 250-ETRN[CR][LF] >Oct-21-09 15:46:27 [Worker_2] <sq: IO::Socket::INET=GLOB(0x963e450) l=10 >Oct-21-09 15:46:27 [Worker_2] <doing line <250-STARTTLS[CR][LF] > >Oct-21-09 15:46:27 [Worker_2] <reply >Oct-21-09 15:46:27 [Worker_2] <reply : 250-STARTTLS[CR][LF] >Oct-21-09 15:46:27 [Worker_2] <doing line <250-AUTH PLAIN LOGIN[CR][LF] > >Oct-21-09 15:46:27 [Worker_2] <reply >Oct-21-09 15:46:27 [Worker_2] <reply : 250-AUTH PLAIN LOGIN[CR][LF] >Oct-21-09 15:46:27 [Worker_2] <sq: IO::Socket::INET=GLOB(0x963e450) l=22 >Oct-21-09 15:46:27 [Worker_2] <doing line <250-AUTH=PLAIN LOGIN[CR][LF] > >Oct-21-09 15:46:27 [Worker_2] <reply >Oct-21-09 15:46:27 [Worker_2] <reply : 250-AUTH=PLAIN LOGIN[CR][LF] >Oct-21-09 15:46:27 [Worker_2] <sq: IO::Socket::INET=GLOB(0x963e450) l=22 >Oct-21-09 15:46:27 [Worker_2] <doing line <250-ENHANCEDSTATUSCODES[CR][LF] > >Oct-21-09 15:46:27 [Worker_2] <reply >Oct-21-09 15:46:27 [Worker_2] <reply : 250-ENHANCEDSTATUSCODES[CR][LF] >Oct-21-09 15:46:27 [Worker_2] <sq: IO::Socket::INET=GLOB(0x963e450) l=25 >Oct-21-09 15:46:27 [Worker_2] <doing line <250-8BITMIME[CR][LF] > >Oct-21-09 15:46:27 [Worker_2] <reply >Oct-21-09 15:46:27 [Worker_2] <reply : 250-8BITMIME[CR][LF] >Oct-21-09 15:46:27 [Worker_2] <sq: IO::Socket::INET=GLOB(0x963e450) l=14 >Oct-21-09 15:46:27 [Worker_2] <doing line <250 DSN[CR][LF] > >Oct-21-09 15:46:27 [Worker_2] <reply >Oct-21-09 15:46:27 [Worker_2] <reply : 250 DSN[CR][LF] >Oct-21-09 15:46:27 [Worker_2] <sq: IO::Socket::INET=GLOB(0x963e450) l=9 >Oct-21-09 15:46:27 [Worker_2] SC-Time Worker_2: 0.00324010848999023 Oct-21-09 15:46:27 [Worker_2] <IO::Socket::INET=GLOB(0x9640fe0) HASH(0x9652ed0) l=0 >Oct-21-09 15:46:27 [Worker_2] <IO::Socket::INET=GLOB(0x963e450) >HASH(0x95f58e0) l=155 >Oct-21-09 15:46:27 [Worker_2] <wrote: IO::Socket::INET=GLOB(0x963e450) >(155)<250-mail.fiwi.at[CR][CR][LF] 250-STARTTLS[CR][LF] 250-SIZE 504800000[CR][LF] 250-ETRN[CR][LF] 250-AUTH PLAIN LOGIN[CR][LF] 250-AUTH=PLAIN LOGIN[CR][LF] 250-ENHANCEDSTATUSCODES[CR][LF] 250-8BITMIME[CR][LF] 250 DSN[CR][LF] > >Oct-21-09 15:46:27 [Worker_2] <SMTPTraffic - read OK >Oct-21-09 15:46:27 [Worker_2] <SMTPTraffic - process read >Oct-21-09 15:46:27 [Worker_2] <doing line <QUIT[CR][LF] > >Oct-21-09 15:46:27 [Worker_2] <getline >Oct-21-09 15:46:27 [Worker_2] <gl: <QUIT[CR][LF] > >Oct-21-09 15:46:27 [Worker_2] <sq: IO::Socket::INET=GLOB(0x9640fe0) l=6 >Oct-21-09 15:46:27 [Worker_2] 81.169.146.161 SC-Time Worker_2: >0.000765085220336914 Oct-21-09 15:46:27 [Worker_2] <IO::Socket::INET=GLOB(0x9640fe0) HASH(0x9652ed0) l=6 >Oct-21-09 15:46:27 [Worker_2] <wrote: IO::Socket::INET=GLOB(0x9640fe0) >(6)<QUIT[CR][LF] > >Oct-21-09 15:46:27 [Worker_2] <SMTPTraffic - no more data - >Oct-21-09 15:46:27 [Worker_2] 81.169.146.161 info: no (more) data readable >from 81.169.146.161 (connection closed by peer) - last command was 'QUIT' Oct-21-09 15:46:27 [Worker_2] 81.169.146.161 SC-Time Worker_2: 0.000452041625976562
Oct-21-09 15:38:23 [Main_Thread] Info: Main_Thread got connection request Oct-21-09 15:38:23 [Main_Thread] Info: Main_Thread looks up the best Worker for new connection - 1 Oct-21-09 15:38:23 [Worker_2] Worker_2 wakes up Oct-21-09 15:38:23 [Worker_2] Info: Worker_2 got connection from MainThread - 1/1 Oct-21-09 15:38:23 [Worker_2] Info: Worker_2 freed Main_Thread - 9 Oct-21-09 15:38:23 [Worker_2] IP 81.169.146.162 (81.169) matches debugIP Oct-21-09 15:38:23 [Main_Thread] Info: Main_Thread will wait (max 30 s) for the answer of Worker_2 which handles 0 sockets Oct-21-09 15:38:23 [Main_Thread] Info: Main_Thread freed by idle Worker_2 in 0.022 seconds Oct-21-09 15:38:23 [Worker_2] Connected: 81.169.146.162:36018 > 85.126.114.2:25 > 85.126.114.2:125 , 9-10 Oct-21-09 15:38:23 [Worker_2] SC-Time Worker_2: 0.000747919082641602 Oct-21-09 15:38:23 [Worker_2] 81.169.146.162 SC-Time Worker_2: 0.0255899429321289 Oct-21-09 15:38:23 [Worker_2] 81.169.146.162 info: faked '250-STARTTLS ready' for 85.126.114.2 Oct-21-09 15:38:23 [Worker_2] SC-Time Worker_2: 0.0119800567626953 Oct-21-09 15:38:23 [Worker_2] 81.169.146.162 SC-Time Worker_2: 0.000629901885986328 Oct-21-09 15:38:23 [Worker_2] 81.169.146.162 info: no (more) data readable from 81.169.146.162 (connection closed by peer) - last command was 'QUIT' Oct-21-09 15:38:23 [Worker_2] 81.169.146.162 SC-Time Worker_2: 0.000474929809570312 Oct-21-09 15:38:23 [Worker_2] Disconnected: 81.169.146.162 - command list was 'EHLO,QUIT' - used 3 SocketCalls Oct-21-09 15:38:23 [Worker_2] Worker_2 prepair to sleep Oct-21-09 15:38:23 [Worker_2] Worker_2 will sleep now Oct-21-09 15:38:24 [Main_Thread] Info: starting partial debug mode to file ./1256132304.dbg Oct-21-09 15:39:22 [Main_Thread] Info: Main_Thread got connection request Oct-21-09 15:39:22 [Main_Thread] Info: Main_Thread looks up the best Worker for new connection - 1 Oct-21-09 15:39:22 [Worker_2] Worker_2 wakes up Oct-21-09 15:39:22 [Worker_2] Info: Worker_2 got connection from MainThread - 1/1 Oct-21-09 15:39:22 [Worker_2] Info: Worker_2 freed Main_Thread - 10 Oct-21-09 15:39:22 [Worker_2] IP 81.169.146.162 (81.169) matches debugIP Oct-21-09 15:39:22 [Main_Thread] Info: Main_Thread will wait (max 30 s) for the answer of Worker_2 which handles 0 sockets Oct-21-09 15:39:22 [Main_Thread] Info: Main_Thread freed by idle Worker_2 in 0.008 seconds Oct-21-09 15:39:22 [Worker_2] Connected: 81.169.146.162:38308 > 85.126.114.2:25 > 85.126.114.2:125 , 10-11 Oct-21-09 15:39:22 [Worker_2] SC-Time Worker_2: 0.00076603889465332 Oct-21-09 15:39:22 [Worker_2] 81.169.146.162 SC-Time Worker_2: 0.00338506698608398 Oct-21-09 15:39:22 [Worker_2] 81.169.146.162 info: faked '250-STARTTLS ready' for 85.126.114.2 Oct-21-09 15:39:22 [Worker_2] SC-Time Worker_2: 0.00324201583862305 Oct-21-09 15:39:22 [Worker_2] 81.169.146.162 SC-Time Worker_2: 0.000609159469604492 Oct-21-09 15:39:22 [Worker_2] 81.169.146.162 info: no (more) data readable from 81.169.146.162 (connection closed by peer) - last command was 'QUIT' Oct-21-09 15:39:22 [Worker_2] 81.169.146.162 SC-Time Worker_2: 0.000463962554931641 Oct-21-09 15:39:22 [Worker_2] Disconnected: 81.169.146.162 - command list was 'EHLO,QUIT' - used 3 SocketCalls Oct-21-09 15:39:22 [Worker_2] Worker_2 prepair to sleep Oct-21-09 15:39:22 [Worker_2] Worker_2 will sleep now Oct-21-09 15:46:27 [Main_Thread] Info: Main_Thread got connection request Oct-21-09 15:46:27 [Main_Thread] Info: Main_Thread looks up the best Worker for new connection - 1 Oct-21-09 15:46:27 [Worker_2] Worker_2 wakes up Oct-21-09 15:46:27 [Worker_2] Info: Worker_2 got connection from MainThread - 1/1 Oct-21-09 15:46:27 [Worker_2] Info: Worker_2 freed Main_Thread - 10 Oct-21-09 15:46:27 [Worker_2] IP 81.169.146.161 (81.169) matches debugIP Oct-21-09 15:46:27 [Worker_2] Connected: 81.169.146.161:56387 > 85.126.114.2:25 > 85.126.114.2:125 , 10-11 Oct-21-09 15:46:27 [Main_Thread] Info: Main_Thread will wait (max 30 s) for the answer of Worker_2 which handles 0 sockets Oct-21-09 15:46:27 [Main_Thread] Info: Main_Thread freed by idle Worker_2 in 0.007 seconds Oct-21-09 15:46:27 [Worker_2] SC-Time Worker_2: 0.000761032104492188 Oct-21-09 15:46:27 [Worker_2] 81.169.146.161 SC-Time Worker_2: 0.00334405899047852 Oct-21-09 15:46:27 [Worker_2] 81.169.146.161 info: faked '250-STARTTLS ready' for 85.126.114.2 Oct-21-09 15:46:27 [Worker_2] SC-Time Worker_2: 0.00324010848999023 Oct-21-09 15:46:27 [Worker_2] 81.169.146.161 SC-Time Worker_2: 0.000765085220336914 Oct-21-09 15:46:27 [Worker_2] 81.169.146.161 info: no (more) data readable from 81.169.146.161 (connection closed by peer) - last command was 'QUIT' Oct-21-09 15:46:27 [Worker_2] 81.169.146.161 SC-Time Worker_2: 0.000452041625976562 Oct-21-09 15:46:27 [Worker_2] Disconnected: 81.169.146.161 - command list was 'EHLO,QUIT' - used 3 SocketCalls Oct-21-09 15:46:27 [Worker_2] Worker_2 prepair to sleep Oct-21-09 15:46:27 [Worker_2] Worker_2 will sleep now
------------------------------------------------------------------------------ Come build with us! The BlackBerry(R) Developer Conference in SF, CA is the only developer event you need to attend this year. Jumpstart your developing skills, take BlackBerry mobile applications to market and stay ahead of the curve. Join us from November 9 - 12, 2009. Register now! http://p.sf.net/sfu/devconference
_______________________________________________ Assp-test mailing list Assp-test@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/assp-test
