Intermittent problems with inbound email

[hratly]

Hi

We have made a couple experimentation with Alfresco 4.0d in our compagny and we are globally quite pleased with the product so far. There's only one problem that I can't fix and I can't seem to put down my finger on it. I configure a space to receive inbound emails from a specific email adress inside our organisation. The configuration seems to work because my space receive approximatly 30% of the emails that it is supposed to receive. Also, in my alfresco.log file, I receive continuously the following error :

2012-02-10 13:52:09,074  ERROR [smtp.server.Session] [org.subethamail.smtp.server.Session-] Unexpected error in the SMTP handler thread
 java.lang.NullPointerException
        at org.alfresco.email.server.EmailServer.filterSender(EmailServer.java:215)
        at org.alfresco.email.server.impl.subetha.SubethaEmailServer.access$200(SubethaEmailServer.java:52)
        at org.alfresco.email.server.impl.subetha.SubethaEmailServer$Handler.from(SubethaEmailServer.java:157)
        at org.subethamail.smtp.command.MailCommand.execute(MailCommand.java:84)
        at org.subethamail.smtp.server.RequireTLSCommandWrapper.execute(RequireTLSCommandWrapper.java:27)
        at org.subethamail.smtp.server.CommandHandler.handleCommand(CommandHandler.java:98)
        at org.subethamail.smtp.server.Session.runCommandLoop(Session.java:222)
        at org.subethamail.smtp.server.Session.run(Session.java:125)
Exception in thread "org.subethamail.smtp.server.Session-/132.203.244.21:12713" java.lang.NullPointerException
        at org.alfresco.email.server.EmailServer.filterSender(EmailServer.java:215)
        at org.alfresco.email.server.impl.subetha.SubethaEmailServer.access$200(SubethaEmailServer.java:52)
        at org.alfresco.email.server.impl.subetha.SubethaEmailServer$Handler.from(SubethaEmailServer.java:157)
        at org.subethamail.smtp.command.MailCommand.execute(MailCommand.java:84)
        at org.subethamail.smtp.server.RequireTLSCommandWrapper.execute(RequireTLSCommandWrapper.java:27)
        at org.subethamail.smtp.server.CommandHandler.handleCommand(CommandHandler.java:98)
        at org.subethamail.smtp.server.Session.runCommandLoop(Session.java:222)
        at org.subethamail.smtp.server.Session.run(Session.java:125)‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

Voici ma configuration email dans alfresco-global.properties :

#
# Outbound Email Configuration
#————-
mail.host=our SMTP server
mail.port=25
mail.from.default=a non-existing local adress

#
# Alfresco Email Service and Email Server
#————-

# Enable/Disable the inbound email service.  The service could be used by processes other than
# the Email Server (e.g. direct RMI access) so this flag is independent of the Email Service.
#————-
email.inbound.enabled=true

# Email Server properties
#————-
email.server.enabled=true
email.server.port=25
email.server.domain=[i]our serveur domain[/i]
email.inbound.unknownUser=anonymous

email.server.hideTLS=false
email.server.enableTLS=true
email.server.requireTLS=false

# A comma separated list of email REGEX patterns of allowed senders.
# If there are any values in the list then all sender email addresses
# must match. For example:
#   .*\@alfresco\.com, .*\@alfresco\.org
# Allow anyone:
#————-
email.server.allowed.senders=.*‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

Does someone has any idea what this error is refering to? I have searched quite a bit on google and I could not find anything related to this.

Thanks!

[mrogers]

Sorry, that's a bug.

May be ALF-11837, but that should be fixed in 4.0 d.

There was a bit of an issue with the "From" and "To" fields could you investigate to see if there's a pattern to the ones failing and the ones succeeding.

[mrogers]

I've just reviewed the code and it looks like yours is a different issue.

In particular I suspect there's something other than an internet address in the SMTP FROM field.

If you turn the following debug logger on then that should make things clear:

log4j.logger.org.subethamail.smtp.server.ConnectionHandler=debug

[hratly]

I've just reviewed the code and it looks like yours is a different issue.

In particular I suspect there's something other than an internet address in the SMTP FROM field.

If you turn the following debug logger on then that should make things clear:

log4j.logger.org.subethamail.smtp.server.ConnectionHandler=debug

Hi,

Thanks for your reply! I already tried to put that line in my log4j.properties (/var/lib/tomcat6/webapps/alfresco/WEB-INF/classes/log4j.properties) file but I'm afraid that my log file does not contains much more information that I already gave you (even if the mail is processed and entered properly in alfresco).

What am I supposed to see in my alfresco.log file?

Thanks!

[rays]

I'm having almost the same issue. I added log4j.logger.org.subethamail.smtp.server.ConnectionHandler=debug to my alfresco-global.properties file but can confirm that no more info than I was already getting in catalina.out is being recorded in alfresco.log after restarting Alfresco.

There's no sign of any SMTP FROM or TO field info etc. in the alfresco.log file.

However, I believe that these errors are occuring on outbound notification emails and consequently, these are not arriving with the daily frequency expected. Global properties file has these related configuration lines:

# Notifications
# ————-

activities.feed.notifier.enabled=true
activities.feed.notifier.repeatIntervalMins=1440

#
# Outbound Email Configuration
#————-
#mail.host=
#mail.port=25
#mail.username=anonymous
#mail.password=
#mail.encoding=UTF-8
#mail.from.default=alfresco@alfresco.org
#mail.smtp.auth=false

mail.host=127.0.0.1
mail.encoding=UTF-8
mail.from.default=no-reply@<our.domain.net>

mail.testmessage.send=true
mail.testmessage.to=admin@<domain.net>
mail.testmessage.subject=<our.domain.net> outbound SMTP
mail.testmessage.text=Outbound SMTP on <our.domain.net> is working

log4j.logger.org.subethamail.smtp.server.ConnectionHandler=debug

#
# Alfresco Email Service and Email Server
#————-

# Enable/Disable the inbound email service.  The service could be used by processes other than
# the Email Server (e.g. direct RMI access) so this flag is independent of the Email Service.
#————-
#email.inbound.enabled=true

email.inbound.enabled=true

# Email Server properties 
#————-
#email.server.enabled=true
#email.server.port=25
#email.server.domain=alfresco.com
#email.inbound.unknownUser=anonymous

email.server.enabled=true
email.server.port=25252
email.server.domain=<our.domain.net>
email.inbound.unknownUser=anonymous


# A comma separated list of email REGEX patterns of allowed senders.
# If there are any values in the list then all sender email addresses
# must match. For example:
#   .*\@alfresco\.com, .*\@alfresco\.org
# Allow anyone:
#————-
#email.server.allowed.senders=.*

email.server.allowed.senders=.*
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

So, what next, please? I think notifications are really helpful for our broad range of users so I'd like to get this SMTP performance issue resolved asap for them.

Thanks, in advance, for your support.

[mrogers]

Need more diagnosis.   This thread was to do with inbound, not outbound email.   And please note that log settings do not go in alfresco-global.properties.

[unknown-user]

Hi,
it looks the same problem, intermittent and from email server:
doc.xxxxxx.xxx is the inbound as in global properties
machine.abc.xxx is the hostname
Why it's talking to himself?

2013-04-02 16:53:56,501  DEBUG [smtp.server.Session] [org.subethamail.smtp.server.Session-/192.168.74.1:38205] SMTP connection from 192.168.74.1/192.168.74.1, new connection count: 1
2013-04-02 16:53:56,501  DEBUG [smtp.server.Session] [org.subethamail.smtp.server.Session-/192.168.74.1:38205] Server: 220 doc.xxxxxx.xxx ESMTP SubEthaSMTP 3.1.6
2013-04-02 16:53:56,502  DEBUG [smtp.server.Session] [org.subethamail.smtp.server.Session-/192.168.74.1:38205] Client: EHLO machine.abc.xxx
2013-04-02 16:53:56,502  DEBUG [smtp.server.Session] [org.subethamail.smtp.server.Session-/192.168.74.1:38205] Server: 250-doc.xxxxxx.xxx
250-8BITMIME
250-AUTH PLAIN LOGIN
250 Ok
2013-04-02 16:53:56,503  DEBUG [smtp.server.Session] [org.subethamail.smtp.server.Session-/192.168.74.1:38205] Client: MAIL FROM:<>
2013-04-02 16:53:56,503  ERROR [smtp.server.Session] [org.subethamail.smtp.server.Session-/192.168.74.1:38205] Unexpected error in the SMTP handler thread
 java.lang.NullPointerException
at org.alfresco.email.server.EmailServer.filterSender(EmailServer.java:215)
at org.alfresco.email.server.impl.subetha.SubethaEmailServer.access$200(SubethaEmailServer.java:52)
at org.alfresco.email.server.impl.subetha.SubethaEmailServer$Handler.from(SubethaEmailServer.java:157)
at org.subethamail.smtp.command.MailCommand.execute(MailCommand.java:84)
at org.subethamail.smtp.server.RequireTLSCommandWrapper.execute(RequireTLSCommandWrapper.java:27)
at org.subethamail.smtp.server.CommandHandler.handleCommand(CommandHandler.java:98)
at org.subethamail.smtp.server.Session.runCommandLoop(Session.java:222)
at org.subethamail.smtp.server.Session.run(Session.java:125)
2013-04-02 16:53:56,503  DEBUG [smtp.server.Session] [org.subethamail.smtp.server.Session-/192.168.74.1:38205] Server: 421 4.3.0 Mail system failure, closing transmission channel
 Exception in thread "org.subethamail.smtp.server.Session-/192.168.74.1:38205" java.lang.NullPointerException
at org.alfresco.email.server.EmailServer.filterSender(EmailServer.java:215)
at org.alfresco.email.server.impl.subetha.SubethaEmailServer.access$200(SubethaEmailServer.java:52)
at org.alfresco.email.server.impl.subetha.SubethaEmailServer$Handler.from(SubethaEmailServer.java:157)
at org.subethamail.smtp.command.MailCommand.execute(MailCommand.java:84)
at org.subethamail.smtp.server.RequireTLSCommandWrapper.execute(RequireTLSCommandWrapper.java:27)
at org.subethamail.smtp.server.CommandHandler.handleCommand(CommandHandler.java:98)
at org.subethamail.smtp.server.Session.runCommandLoop(Session.java:222)
at org.subethamail.smtp.server.Session.run(Session.java:125)
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

[mcasanket]

Hi,

Have you got anything useful on this? I have just upgraded the system from 3.2.2.7 to 3.4.11 and I am also getting the same error. Finally it gives out of memory error. When I raised the ticket in Alfresco they told me that my email server is sending empty MAIL FROM and that is why it is coming null. Please help.


Exception:
00:28:15,728  ERROR [smtp.server.Session] Unexpected error in the SMTP handler thread
java.lang.NullPointerException
   at org.alfresco.email.server.EmailServer.filterSender(EmailServer.java:219)
   at org.alfresco.email.server.impl.subetha.SubethaEmailServer.access$100(SubethaEmailServer.java:47)
   at org.alfresco.email.server.impl.subetha.SubethaEmailServer$Handler.from(SubethaEmailServer.java:133)
   at org.subethamail.smtp.command.MailCommand.execute(MailCommand.java:84)
   at org.subethamail.smtp.server.RequireTLSCommandWrapper.execute(RequireTLSCommandWrapper.java:27)
   at org.subethamail.smtp.server.CommandHandler.handleCommand(CommandHandler.java:98)
   at org.subethamail.smtp.server.Session.runCommandLoop(Session.java:222)
   at org.subethamail.smtp.server.Session.run(Session.java:125)
Exception in thread "org.subethamail.smtp.server.Session-/10.1.1.108:14067" java.lang.NullPointerException
   at org.alfresco.email.server.EmailServer.filterSender(EmailServer.java:219)
   at org.alfresco.email.server.impl.subetha.SubethaEmailServer.access$100(SubethaEmailServer.java:47)
   at org.alfresco.email.server.impl.subetha.SubethaEmailServer$Handler.from(SubethaEmailServer.java:133)
   at org.subethamail.smtp.command.MailCommand.execute(MailCommand.java:84)
   at org.subethamail.smtp.server.RequireTLSCommandWrapper.execute(RequireTLSCommandWrapper.java:27)
   at org.subethamail.smtp.server.CommandHandler.handleCommand(CommandHandler.java:98)
   at org.subethamail.smtp.server.Session.runCommandLoop(Session.java:222)
   at org.subethamail.smtp.server.Session.run(Session.java:125)
Exception in thread "indexThread7" java.lang.OutOfMemoryError: Java heap space
Exception in thread "RMI RenewClean-[10.1.1.122:51602]" Exception in thread "RMI RenewClean-[10.1.1.122:62101]" java.lang.OutOfMemoryError: Java heap space
Exception in thread "org.subethamail.smtp.server.ServerThread *:25"

[mrogers]

Indeed it does look like an empty FROM field.    Could you get some diagnostics like a wireshark capture of the SMTP message or logging of the SMTP message from alfresco.

In addition you also have an OutOfMemory error, which normally means that you havn't set PermGen high enough.

[mcasanket]

Hi Mrogers,

Thanks for your reply. We are having 32 GB RAM. We have set 1024 for PrmGen and MamimumMemoryPool 14336. The permGen size and MaxMemorypool size can be increased to what number. See the attached image.

Thank you!