[SOLVED]Outbound email didn't go to customer

jag · June 8, 2007, 10:54pm

Hi, all. I am new to MCR 7.5, just finished installation of email part. But when I follow the deployment guide to test “ABC Simple BP” process, everything is fine until agent replies email back to customer. I set “default-inbound-queue=Inbound queue” for E-Mail Server and “email-default-queue=Inbound queue”, “email-outbound-queue=Outbound queue” for Genesys Desktop. The problem is when “E-Mail Server for Java” connects to SMTP server and sends out the email, it’s successfully sent according to genesys log. But on SMTP server log, the connection was timeout hence no email sent to customer. SMTP server is working well since I test it with outlook. Pls can anyone help me on this? Thanks a lot!

I just post some of the log file, detail log can be find on attached document.

-Unsuccessful email sent from Genesys
6/8/2007 11:21:01 AM - Requested SMTP connection from 172.16.64.84
6/8/2007 11:21:01 AM - ( 85) 220 GEN75 ArGoSoft Mail Server Freeware, Version 1.8 (1.8.8.2)
6/8/2007 11:21:01 AM - ( 85) EHLO GEN75
6/8/2007 11:21:01 AM - ( 85) 250-Welcome [172.16.64.84], pleased to meet you
6/8/2007 11:21:01 AM - ( 85) 250-SIZE 5242880
6/8/2007 11:21:01 AM - ( 85) 250 HELP
6/8/2007 11:21:01 AM - ( 85) MAIL FROM:<[email removed]>
6/8/2007 11:21:01 AM - ( 85) 250 Sender “[email removed]” OK…
6/8/2007 11:21:01 AM - ( 85) RCPT TO:<[email removed]>
6/8/2007 11:21:01 AM - ( 85) 250 Recipient “[email removed]” OK…
6/8/2007 11:21:02 AM - ( 85) RSET
6/8/2007 11:21:02 AM - ( 85) 250 Reset state
6/8/2007 11:21:21 AM - Requested POP3 connection from 172.16.64.84
6/8/2007 11:21:21 AM - Requested POP3 connection from 172.16.64.84
6/8/2007 11:21:21 AM - POP3 connection with 172.16.64.84 ended. ID=86
6/8/2007 11:21:21 AM - POP3 connection with 172.16.64.84 ended. ID=87
6/8/2007 11:21:51 AM - Requested POP3 connection from 172.16.64.84
6/8/2007 11:21:52 AM - Requested POP3 connection from 172.16.64.84
6/8/2007 11:21:52 AM - POP3 connection with 172.16.64.84 ended. ID=88
6/8/2007 11:21:52 AM - POP3 connection with 172.16.64.84 ended. ID=89
-Seems to be 1 mins timeout on ArGo SMTP Server
6/8/2007 11:22:01 AM - Error: Operation has been canceled
6/8/2007 11:22:01 AM - SMTP connection with 172.16.64.84 ended. ID=85
6/8/2007 11:22:22 AM - Requested POP3 connection from 172.16.64.84
6/8/2007 11:22:22 AM - Requested POP3 connection from 172.16.64.84

while a normal log file should be this kind

-Successful email sent from Outlook to Genesys
6/8/2007 11:20:03 AM - Requested SMTP connection from 172.16.64.84
6/8/2007 11:20:03 AM - ( 79) 220 GEN75 ArGoSoft Mail Server Freeware, Version 1.8 (1.8.8.2)
6/8/2007 11:20:03 AM - ( 79) HELO GEN75
6/8/2007 11:20:03 AM - ( 79) 250 Welcome [172.16.64.84], pleased to meet you
6/8/2007 11:20:04 AM - ( 79) MAIL FROM: <[email removed]>
6/8/2007 11:20:04 AM - ( 79) 250 Sender “[email removed]” OK…
6/8/2007 11:20:04 AM - ( 79) RCPT TO: <[email removed]>
6/8/2007 11:20:04 AM - ( 79) 250 Recipient “[email removed]” OK…
6/8/2007 11:20:04 AM - ( 79) RSET
6/8/2007 11:20:04 AM - ( 79) 250 Reset state
6/8/2007 11:20:04 AM - ( 79) RSET
6/8/2007 11:20:04 AM - ( 79) 250 Reset state
6/8/2007 11:20:05 AM - ( 79) MAIL FROM: <[email removed]>
6/8/2007 11:20:05 AM - ( 79) 250 Sender “[email removed]” OK…
6/8/2007 11:20:05 AM - ( 79) RCPT TO: <[email removed]>
6/8/2007 11:20:05 AM - ( 79) 250 Recipient “[email removed]” OK…
6/8/2007 11:20:05 AM - ( 79) DATA
6/8/2007 11:20:05 AM - ( 79) 354 Enter mail, end with “.” on a line by itself
6/8/2007 11:20:05 AM - Received 520 bytes
6/8/2007 11:20:05 AM - ( 79) 250 Message accepted for delivery.
6/8/2007 11:20:06 AM - [ 80] Delivering to [email removed]
6/8/2007 11:20:06 AM - [ 80] Message from [email removed] delivered to [email removed]
6/8/2007 11:20:06 AM - ( 79) QUIT
6/8/2007 11:20:06 AM - ( 79) 221 Aba he
6/8/2007 11:20:06 AM - SMTP connection with 172.16.64.84 ended. ID=79

cavagnaro · June 9, 2007, 6:48pm

Seems an error on ArgoSoft, try to restart the Service. Seems the Pop3 module is not working ok.

Rene · June 10, 2007, 2:01pm

Hi,

Freeware version of ArgoSoft Mail Server doesn’t allow you to send an email with size over 5 MB.

René

victor1 · June 11, 2007, 12:09am

6/8/2007 11:21:01 AM - ( 85) 250-SIZE 5242880

If you look here, you will see that there is a max of 5 megs per message:

http://www.argosoft.com/rootpages/MailServer/Default.aspx

Of course, there is no descriptive error for that, so you are stuck wondering

Best regards,
Vic

jag · June 11, 2007, 5:31pm

Thanks for response! I move my ArGo Mail server to pro version, but unlucky the problem still there. BTW, how come the size will excess 5MB since it’s only a “hello world” mail. Is there anything related to the version? My Genesys email server version is 7.5.000.11

cavagnaro · June 11, 2007, 5:36pm

Have you configured your Argosoft?

From Admin Manual:

Into the Message Size Limit select your value. This is the single email size that can be sent. Note, if you use “Unlimited“ the mail server will use more resources to run, so pay attention to this value. If you don’t need to send much data I suggest selecting 5 MB as Size Limit.

Rene · June 11, 2007, 5:48pm

Hi Jag,

Could you enable debug logging for smtp-client of ESJ and put the logs here? It’s the key “enable-debug” in “smtp-client” section of ESJ’ options.

I’m using ArgoSoft Mail Server Freeware with the same version of ESJ and everything is working fine.

R.

jag · June 11, 2007, 8:27pm

Thanks René, pls compare this with yours

GEN75 is the hostname, while it’s an all-in-one box made on vmware.

4:20:34.625 Trc 25096 [SvcSrvW-0] <7> Request (queued for 0 ms): Id=7|Type=Request|Service=Email|Method=Send.
14:20:34.656 Trc 25019 [SvcSrvW-0] <7 00004a36UA5C000S GEN75:2511> Service ‘Email’ method ‘Send’ started.
14:20:34.656 Trc 23191 [SvcSrvW-0] <7 00004a36UA5C000S GEN75:2511> Request: Type=Request|Service=Email|Method=Send|Parameters=[CustomizedSubject=“”|MessageDispositionNotification=“true”|DeliveryStatusNotification=“true”]|UserData=[InteractionSubtype=“OutboundNew”|SubmittedBy=“Place_2901_Mutlimedia”|IsOnline=0|DeliveredAt=“2007-06-11T20:20:04Z”|To=“[email removed]”|MovedToQueueAt=“2007-06-11T20:20:04Z”|Queue=“Outbound queue”|MediaType=“email”|FromAddress=“[email removed]”|IsLocked=0|PlacedInQueueAt=“2007-06-11T20:20:31Z”|ReceivedAt=“2007-06-11T20:20:04Z”|InteractionType=“Outbound”|ContactId=“00002a36GBW8000M”|InteractionState=1|InteractionId=“00004a36UA5C000S”|Subject=“hello world”|GD_OriginalAgentEmployeeId=“Employee_ID_2901_Multimedia”|SubmittedAt=“2007-06-11T20:20:04Z”|TenantId=101].
14:20:34.734 Dbg 23081 [SvcSrvW-0] <7 00004a36UA5C000S> Sender : findById 00004a36UA5C000S.
14:20:34.750 Dbg 23082 [SvcSrvW-0] <7 00004a36UA5C000S> Sender : findById done.
14:20:34.750 Dbg 23090 [SvcSrvW-0] <7 00004a36UA5C000S> Sender : mark as reserved 00004a36UA5C000S.
14:20:34.828 Dbg 23092 [SvcSrvW-0] <7 00004a36UA5C000S> Sender : mark as reserved done 00004a36UA5C000S.
14:20:34.828 Dbg 23072 [SvcSrvW-0] <7 00004a36UA5C000S> ‘From’ address : [email removed]
14:20:34.828 Dbg 23107 [SvcSrvW-0] <7 00004a36UA5C000S> Candidate ‘To’ addresses : [[email removed]]
14:20:34.828 Dbg 23107 [SvcSrvW-0] <7 00004a36UA5C000S> Candidate ‘Cc’ addresses :
14:20:34.828 Dbg 23107 [SvcSrvW-0] <7 00004a36UA5C000S> Candidate ‘Bcc’ addresses :
14:20:34.828 Dbg 23111 [SvcSrvW-0] <7 00004a36UA5C000S> Excluded addresses : [[email removed], [email removed]]
14:20:34.828 Dbg 23112 [SvcSrvW-0] <7 00004a36UA5C000S> Actual ‘To’ addresses : [[email removed]]
14:20:34.828 Dbg 23112 [SvcSrvW-0] <7 00004a36UA5C000S> Actual ‘Cc’ addresses :
14:20:34.828 Dbg 23112 [SvcSrvW-0] <7 00004a36UA5C000S> Actual ‘Bcc’ addresses :
14:20:35.171 Dbg 23073 [SvcSrvW-0] <7 00004a36UA5C000S> UserData : [FromPersonal=“”|ContactId=“00002a36GBW8000M”|_AttachmentsSize=“0”|GD_OriginalAgentEmployeeId=“Employee_ID_2901_Multimedia”|Subject=“hello world”|To=“[email removed]”|_ContainsAttachment=“false”|FromAddress=“[email removed]”].
14:20:35.187 Dbg 23083 [SvcSrvW-0] <7 00004a36UA5C000S> Acquiring new SMTP connection from pool (current total nb of connections: 0 , free connections: 0 , used connections: 0).
14:20:35.187 Dbg 23104 [SvcSrvW-0] <7 00004a36UA5C000S> Creating SMTP connection nb 1.
14:20:35.187 Dbg 23100 [SvcSrvW-0] <7 00004a36UA5C000S> Activating SMTP connection nb 1.
14:20:35.203 Dbg 25111 [SvcSrvW-0] <7 00004a36UA5C000S> JavaMail SMTP: DEBUG: getProvider() returning javax.mail.Provider[TRANSPORT,smtp,com.sun.mail.smtp.SMTPTransport,Sun Microsystems, Inc]
14:20:35.234 Trc 04500 Connecting to server ‘smtp’ at host ‘localhost’, port 25
14:20:35.234 Dbg 25111 [SvcSrvW-0] <7 00004a36UA5C000S> JavaMail SMTP: DEBUG SMTP: useEhlo true, useAuth false
14:20:35.234 Dbg 25111 [SvcSrvW-0] <7 00004a36UA5C000S> JavaMail SMTP: DEBUG SMTP: trying to connect to host “localhost”, port 25, isSSL false
14:20:35.250 Dbg 25111 [SvcSrvW-0] <7 00004a36UA5C000S> JavaMail SMTP: 220 GEN75 ArGoSoft Mail Server Freeware, Version 1.8 (1.8.8.2)
DEBUG SMTP: connected to host “localhost”, port: 25

14:20:35.375 Dbg 25111 [SvcSrvW-0] <7 00004a36UA5C000S> JavaMail SMTP: EHLO GEN75
250-Welcome [127.0.0.1], pleased to meet you
250-SIZE 5242880
250 HELP
DEBUG SMTP: Found extension “SIZE”, arg “5242880”
14:20:35.375 Dbg 25111 [SvcSrvW-0] <7 00004a36UA5C000S> JavaMail SMTP: DEBUG SMTP: Found extension “HELP”, arg “”
14:20:35.375 Dbg 23007 [SvcSrvW-0] <7 00004a36UA5C000S> Connected to ‘localhost’, port = 25.
14:20:35.375 Dbg 23084 [SvcSrvW-0] <7 00004a36UA5C000S> Acquired new SMTP connection from pool in 188 ms.
14:20:35.375 Dbg 23085 [SvcSrvW-0] <7 00004a36UA5C000S> Sending message ‘<[email removed]>’…
14:20:35.375 Dbg 25111 [SvcSrvW-0] <7 00004a36UA5C000S> JavaMail SMTP: DEBUG SMTP: use8bit false
14:20:35.765 Dbg 25111 [SvcSrvW-0] <7 00004a36UA5C000S> JavaMail SMTP: MAIL FROM:<[email removed]>
250 Sender “[email removed]” OK…
RCPT TO:<[email removed]>
250 Recipient “[email removed]” OK…
DEBUG SMTP: Verified Addresses
14:20:35.781 Dbg 25111 [SvcSrvW-0] <7 00004a36UA5C000S> JavaMail SMTP: DEBUG SMTP: [email removed]
14:20:35.796 Dbg 23086 [SvcSrvW-0] <7 00004a36UA5C000S> Message sent in 421 ms.
14:20:35.796 Dbg 23087 [SvcSrvW-0] <7 00004a36UA5C000S> Returning SMTP connection into the pool.
14:20:35.796 Dbg 23106 [SvcSrvW-0] <7 00004a36UA5C000S> Passivating SMTP connection nb 1.
14:20:35.812 Trc 21629 [SvcSrvW-0] <7 00004a36UA5C000S> Message ‘<[email removed]>’ sent successfully.
14:20:35.812 Dbg 23093 [SvcSrvW-0] <7 00004a36UA5C000S> Sender : update EmailOut 00004a36UA5C000S.
14:20:36.062 Dbg 23095 [SvcSrvW-0] <7 00004a36UA5C000S> Sender : update EmailOut done 00004a36UA5C000S.
14:20:36.062 Trc 25020 [SvcSrvW-0] <7 00004a36UA5C000S> Service ‘Email’ method ‘Send’ ended, processing time (ms): 1406.
14:20:36.062 Trc 23191 [SvcSrvW-0] <7 00004a36UA5C000S> Response: Type=Response|Service=Email|Method=Send|Parameters=|UserData=.
14:20:36.062 Trc 25097 [SvcSrvW-0] <7> Response: Id=7|Type=Response|Service=Email|Method=Send.
14:20:36.062 Trc 25098 [SvcSrvW-0] <7> ‘Email.Send’ (request id 7) handling duration : 1437 ms.

victor1 · June 12, 2007, 6:30am

Hmmm, ok, it looks like email went through successfully (and it is Freeware still):

4:20:35.250 Dbg 25111 [SvcSrvW-0] <7 00004a36UA5C000S> JavaMail SMTP: 220 GEN75 ArGoSoft Mail Server Freeware, Version 1.8 (1.8.8.2)
DEBUG SMTP: connected to host “localhost”, port: 25

14:20:35.375 Dbg 25111 [SvcSrvW-0] <7 00004a36UA5C000S> JavaMail SMTP: EHLO GEN75
250-Welcome [127.0.0.1], pleased to meet you
250-SIZE 5242880
250 HELP
DEBUG SMTP: Found extension “SIZE”, arg “5242880”
14:20:35.375 Dbg 25111 [SvcSrvW-0] <7 00004a36UA5C000S> JavaMail SMTP: DEBUG SMTP: Found extension “HELP”, arg “”
14:20:35.375 Dbg 23007 [SvcSrvW-0] <7 00004a36UA5C000S> Connected to ‘localhost’, port = 25.
14:20:35.375 Dbg 23084 [SvcSrvW-0] <7 00004a36UA5C000S> Acquired new SMTP connection from pool in 188 ms.
14:20:35.375 Dbg 23085 [SvcSrvW-0] <7 00004a36UA5C000S> Sending message ‘<[email removed]>’…
14:20:35.375 Dbg 25111 [SvcSrvW-0] <7 00004a36UA5C000S> JavaMail SMTP: DEBUG SMTP: use8bit false
14:20:35.765 Dbg 25111 [SvcSrvW-0] <7 00004a36UA5C000S> JavaMail SMTP: MAIL FROM:<[email removed]>
250 Sender “[email removed]” OK…
RCPT TO:<[email removed]>
250 Recipient “[email removed]” OK…
DEBUG SMTP: Verified Addresses
14:20:35.781 Dbg 25111 [SvcSrvW-0] <7 00004a36UA5C000S> JavaMail SMTP: DEBUG SMTP: [email removed]
14:20:35.796 Dbg 23086 [SvcSrvW-0] <7 00004a36UA5C000S> Message sent in 421 ms.
14:20:35.796 Dbg 23087 [SvcSrvW-0] <7 00004a36UA5C000S> Returning SMTP connection into the pool.
14:20:35.796 Dbg 23106 [SvcSrvW-0] <7 00004a36UA5C000S> Passivating SMTP connection nb 1.
14:20:35.812 Trc 21629 [SvcSrvW-0] <7 00004a36UA5C000S> Message ‘<[email removed]>’ sent successfully.
14:20:35.812 Dbg 23093 [SvcSrvW-0] <7 00004a36UA5C000S> Sender : update EmailOut 00004a36UA5C000S.
14:20:36.062 Dbg 23095 [SvcSrvW-0] <7 00004a36UA5C000S> Sender : update EmailOut done 00004a36UA5C000S.
14:20:36.062 Trc 25020 [SvcSrvW-0] <7 00004a36UA5C000S> Service ‘Email’ method ‘Send’ ended, processing time (ms): 1406.

What did I miss?

Rene · June 12, 2007, 9:51am

I do agree with Victor. Based on the log the email was sent successfully.

R.

jag · June 12, 2007, 4:50pm

yes, I switch back to freeware version since there is no time limitation on it
I agree that email was sent according to ESJ log. But what confuses me is why there are two sections in Argo’s log for normal SMTP conversation while the ESJ conversation only has one part. I know nothing about SMTP protocol ;D.

6/8/2007 11:20:04 AM - ( 79) MAIL FROM: <[email removed]>
6/8/2007 11:20:04 AM - ( 79) 250 Sender “[email removed]” OK…
6/8/2007 11:20:04 AM - ( 79) RCPT TO: <[email removed]>
6/8/2007 11:20:04 AM - ( 79) 250 Recipient “[email removed]” OK…
6/8/2007 11:20:04 AM - ( 79) RSET
6/8/2007 11:20:04 AM - ( 79) 250 Reset state
6/8/2007 11:20:04 AM - ( 79) RSET
6/8/2007 11:20:04 AM - ( 79) 250 Reset state
6/8/2007 11:20:05 AM - ( 79) MAIL FROM: <[email removed]>
6/8/2007 11:20:05 AM - ( 79) 250 Sender “[email removed]” OK…
6/8/2007 11:20:05 AM - ( 79) RCPT TO: <[email removed]>
6/8/2007 11:20:05 AM - ( 79) 250 Recipient “[email removed]” OK…
6/8/2007 11:20:05 AM - ( 79) DATA
6/8/2007 11:20:05 AM - ( 79) 354 Enter mail, end with “.” on a line by itself
6/8/2007 11:20:05 AM - Received 520 bytes

Rene · June 12, 2007, 7:19pm

I repeated your test on my lab and there are no “RSET” commands generated by the mail server. I have no clue why this resets appear in your log…

My environment:

Genesys CIM + Email 7.2 installed on one physical machine
Genesys Email Server Java 7.5.000.11
ArGoSoft Mail Server Freeware version 1.8.8.7

R.

jag · June 12, 2007, 8:04pm

René

Can you post your log for both ESJ and Argo here? Thanks

jag · June 12, 2007, 9:23pm

Good news ;D

Thanks a lot René! The “RSET” leads me to find out what the root cause is.

Actually I had Norton Antivirus on my vmware machine and it has a feature called “Internet E-mail Auto-Protect”, when enabled, as I assume, it will intercept every email going out and scan it. That’s why there is a “RSET” which should be interperated as reset showing on SMTP server log, indicating this feature is reseting the connection. This feature can work well with outlook but sure has conflict with ESJ. After I turn off the feature, there are no more “RSET” and only one appearence of From/To address, and everything is working well.

Thanks again for everyone who contirbutes on this thread!