Hi Garry,
First I would like to breakdown the issue here. The issue is related to increased backlog on customers Zimbra MTA server. From Zimbra logs we can see below. postfix/smtp[27416]: 0B1BC125BAA: conversation with <Domain_name>[James machine 1] timed out while sending end of data -- message may be sent more than once postfix/smtp[27416]: 0B1BC125BAA: conversation with <Domain_name>[James Machine 2] timed out while sending end of data -- message may be sent more than once We can see lot of such errors in customer Zimbra logs. Customer is using 3 James setup on different machines to process emails from this Zimbra server. A DNS has been setup on Zimbra end to direct the mails to different James servers for processing. Customer is facing this issue on every Tuesday and not on other days. The backlog starts building up during the start of the day and by evening eventually all the emails on the back log is processed by the James server. So the main concern here is performance related. As in the James SMTP logs we can only see "Caused by: java.net.ProtocolException: pre-mature end of data" exception and nothing else. All the emails gets cleared at end of the day. Customers concern is why the backlog happens on Tuesday, as it increases the load on their MTA server. We suspect this may be related to some network issue from customer end, as we don't see any network related timeouts in James logs. Note: Communication between Zimbra and James happens via TLSv1.2 We have few questions from James end if anyone can help us on this: 1. Is it possible that James can refuse some emails because at some point of time it may run out of resources to process that email ? 2. If James is refusing the emails is there anyway to find it out ? 3. Is there any way to find out that James is not refusing any emails and the issue is from Zimbra side ? 4. Can we increase some performance counters in James like number of thread and connection that may help ? Sharing some SMTP Logs on how communication starts: 20/07/21 13:07:21 INFO smtpserver-tls: TLSProxy(CR#1): client command: EHLO 20/07/21 13:07:21 DEBUG smtpserver-tls: 1626800841447: TLSProxy(CR#1): flushed from Client: EHLO <Domain Name> 20/07/21 13:07:21 DEBUG smtpserver-tls: Lookup command handler for command: EHLO 20/07/21 13:07:21 DEBUG smtpserver-tls: Sent: 250-IBMContentCollectorSMTPReceiver_(DUTL73) Hello <Domain Name> (127.0.0.1 [127.0.0.1]) 20/07/21 13:07:21 DEBUG smtpserver-tls: Sent: 250-PIPELINING 20/07/21 13:07:21 DEBUG smtpserver-tls: Sent: 250 ENHANCEDSTATUSCODES 20/07/21 13:07:21 DEBUG smtpserver-tls: Calling reset() default Worker #4 20/07/21 13:07:21 INFO smtpserver-tls: TLSProxy(CR#1): addind STARTTLS HEADER to james EHLO response 20/07/21 13:07:21 INFO smtpserver-tls: TLSProxy(CR#1): sending to client: 250-IBMContentCollectorSMTPReceiver_(DUTL73) Hello <Domain Name> (127.0.0.1 [127.0.0.1]) 20/07/21 13:07:21 DEBUG smtpserver-tls: 1626800841463: TLSProxy(CR#1): flushed from James: 250-IBMContentCollectorSMTPReceiver_(DUTL73) Hello <Domain Name> (127.0.0.1 [127.0.0.1]) 20/07/21 13:07:21 INFO smtpserver-tls: TLSProxy(CR#1): sending to client: 250-PIPELINING 20/07/21 13:07:21 DEBUG smtpserver-tls: 1626800841463: TLSProxy(CR#1): flushed from James: 250-PIPELINING 20/07/21 13:07:21 INFO smtpserver-tls: TLSProxy(CR#1): sending to client: 250-ENHANCEDSTATUSCODES 20/07/21 13:07:21 DEBUG smtpserver-tls: 1626800841463: TLSProxy(CR#1): flushed from James: 250-ENHANCEDSTATUSCODES 20/07/21 13:07:21 INFO smtpserver-tls: TLSProxy(CR#1): sending to client: 250 STARTTLS 20/07/21 13:07:21 DEBUG smtpserver-tls: 1626800841463: TLSProxy(CR#1): flushed from James: 250 STARTTLS 20/07/21 13:07:21 INFO smtpserver-tls: TLSProxy(CR#1): client command: STARTTLS 20/07/21 13:07:21 INFO smtpserver-tls: TLSProxy(CR#1): sending to client: 220 Go ahead 20/07/21 13:07:21 DEBUG smtpserver-tls: 1626800841494: TLSProxy(CR#1): flushed from TLSProxy: 220 Go ahead 20/07/21 13:07:21 INFO smtpserver-tls: TLSProxy(CR#1): Start switching to SSL socket. Current socket is Socket[addr=/<IP_address>,port=36114,localport=25] 20/07/21 13:07:21 DEBUG smtpserver-tls: TLSProxy(CR#1): Start switching to SSL socket by starting handshake 20/07/21 13:07:21 INFO smtpserver-tls: TLSProxy(CR#1): Start switching to SSL socket. New SSL socket is fb597f16[SSL_ECDHE_RSA_WITH_AES_128_GCM_SHA256: Socket[addr=<Domain Name>/<IP_address>,port=36114,localport=25]] 20/07/21 13:07:21 INFO smtpserver-tls: TLSProxy(CR#1): Client socket using protocol TLSv1.2 20/07/21 13:07:21 INFO smtpserver-tls: TLSProxy(CR#1): Reader and writer re-initialized 20/07/21 13:07:21 INFO smtpserver-tls: TLSProxy(CR#1): Handing over to James Error queue: Are you taking about this "james-2.3.2\apps\james\var\mail\error" error queue ? Regarding error queue I will check on that on customers machine and get back. But At the end of the day all the emails are processed. So not sure if error queue will contain anything. Also have checked the input and output streams and writers. We do not see any charset set on these. So assuming it must be using default. Thanks, Anup -----Original Message----- From: Garry Hurley <[email protected]> Sent: 05 August 2021 01:11 To: James Users List <[email protected]> Subject: Re: Help on James 2.3.2 on production Okay, so, let's look at the RFC-822 email standard. The steps are simply as follows: 1. connect to server 2. send initiation command. (HELO or EHLO) 3. Send MAIL TO command (MAIL TO: [email protected]) 4. Send From command (FROM: [email protected]) 5. Send Data command to start message (DATA) 6. (Optional) Set message Subject on its own line (SUBJECT: My email subject line followed by two enter key strokes) 7. Enter data 8. Terminate message with a period (.) on its own line to send message. Some modern email clients do not do that period at the end of the message. If your client terminates the connection before sending that termination period, you will get some kind of error, most likely the one you are seeing. HOWEVER, if this is an externally originating email, there could be a stray null character in the data stream. A null character would be the same as sending an empty string, and even if the string had other characters after the null, it would not be read. Another possibility is that you are using a Unicode character set wherein the two or four byte character is being broken down to UTF-8 or worse, ASCII, and the border between characters is translating as a transmission end character followed by several other one-byte characters. For the character mapping issue I am referring to, look at https://en.wikipedia.org/wiki/End-of-Transmission_character and see if you are getting that. Check your error queue for the message and see if there is anything in there. On Wed, Aug 4, 2021 at 1:59 AM Anupkumar Seth <[email protected]> wrote: > Hi All, > > We are using James 2.3.2 in our production and started to see some > issues for one of the customer who is using SMTP feature to send email > to James and this email will be stored on local disk. Customer is > using Zimbra mail server. > > We understand James 2.3.2 very old version and is out of support. But > if anyone is still using James 2.3.2 and can help us on error that we > are can see in James logs. > > Recently we found this conversation where Noel J. Bergman had offered > to help on any issue on 2.3.2. please find the link below. > https://www.mail-archive.com/[email protected]/msg70615.html > > > Exception we see in James logs: > > 08/07/21 14:41:21 ERROR smtpserver-tls: Unknown error occurred while > processing DATA. > javax.mail.MessagingException: Error in input stream; > nested exception is: > java.net.ProtocolException: pre-mature end of data > at javax.mail.internet.InternetHeaders.load(InternetHeaders.java:365) > at org.apache.james.core.MailHeaders.<init>(MailHeaders.java:61) > at > org.apache.james.smtpserver.DataCmdHandler.doDATA(DataCmdHandler.java:131) > at > org.apache.james.smtpserver.DataCmdHandler.onCommand(DataCmdHandler.java:81) > at > org.apache.james.smtpserver.SMTPHandler.handleConnection(SMTPHandler.java:393) > at > org.apache.james.util.connection.ServerConnection$ClientConnectionRunner.run(ServerConnection.java:432) > at > org.apache.excalibur.thread.impl.ExecutableRunnable.execute(ExecutableRunnable.java:55) > at > org.apache.excalibur.thread.impl.WorkerThread.run(WorkerThread.java:11 > 6) Caused by: java.net.ProtocolException: pre-mature end of data > at > org.apache.james.util.CharTerminatedInputStream.read(CharTerminatedInputStream.java:103) > at > org.apache.james.util.watchdog.BytesReadResetInputStream.read(BytesReadResetInputStream.java:98) > at > org.apache.james.util.DotStuffingInputStream.read(DotStuffingInputStream.java:50) > at com.sun.mail.util.LineInputStream.readLine(LineInputStream.java:88) > at javax.mail.internet.InternetHeaders.load(InternetHeaders.java:342) > ... 7 more > > We have also found following code snippet from > CharTerminatedInputStream.java which says the same. > > if (b == -1) { > //End of stream reached without seeing the terminator > throw new java.net.ProtocolException("pre-mature end > of data"); > } > > > We suspect that this error is thrown when there is no termination is > sent by the email data and end of stream is reached. We also observer > for some of the email transfer, after the DATA command is issued we > also see RESET command in the middle of data transfer after which > there is no data received from mail server, is this normal behaviour ? > > > This issue is intermittent and does not happen for every email. We > also cannot identify for which email transfer this error is thrown. We > feel this issue may be due to some network related issue from Zimbra > server which is failing to send full data to James server. Is our > understanding correct here ? > > Any help will be really appreciated. > > Thanks & Regards, > Anup > DISCLAIMER > ========== > This e-mail may contain privileged and confidential information which > is the property of Persistent Systems Ltd. It is intended only for the > use of the individual or entity to which it is addressed. If you are > not the intended recipient, you are not authorized to read, retain, > copy, print, distribute or use this message. If you have received this > communication in error, please notify the sender and delete all copies of > this message. > Persistent Systems Ltd. does not accept any liability for virus > infected mails. > DISCLAIMER ========== This e-mail may contain privileged and confidential information which is the property of Persistent Systems Ltd. It is intended only for the use of the individual or entity to which it is addressed. If you are not the intended recipient, you are not authorized to read, retain, copy, print, distribute or use this message. If you have received this communication in error, please notify the sender and delete all copies of this message. Persistent Systems Ltd. does not accept any liability for virus infected mails.
