Problem with email message processing/solr

[idwright]

Hi,
I'm seeing a problem in the logs with Email message processing that seems to be connected to the solr processing.

I've replaced the invalid number which is an alphanumeric in the log entry below as it's different for different errors - but not a number in any of the error messages - no obvious pattern although one value was mysmtp122

I've tried searching for the string that causes the messages in the contentstore using grep without any hits.

I guess something is defined in solr as a number when it shouldn't be but I'm not sure how to narrow it down further

The message is occurring reasonably frequently but I don't know whether it's from the imap server or the smtp server both are enabled.

Any ideas?

Thanks.

The logs are as follows:

On the share server

ERROR [surf.util.AbstractLifecycleBean] [org.subethamail.smtp.server.Session-/an.ip.addr.ess:18150] 10304468 Email message processing failed
 org.alfresco.error.AlfrescoRuntimeException: 10304468 Email message processing failed
        at org.alfresco.email.server.EmailServiceImpl.processMessage(EmailServiceImpl.java:324)
        at org.alfresco.email.server.EmailServiceImpl.importMessage(EmailServiceImpl.java:180)
        at org.alfresco.email.server.impl.subetha.SubethaEmailServer$Handler.processDelivery(SubethaEmailServer.java:223)
        at org.alfresco.email.server.impl.subetha.SubethaEmailServer$Handler.data(SubethaEmailServer.java:184)
        at org.subethamail.smtp.command.DataCommand.execute(DataCommand.java:64)
        at org.subethamail.smtp.server.RequireTLSCommandWrapper.execute(RequireTLSCommandWrapper.java:30)
        at org.subethamail.smtp.server.CommandHandler.handleCommand(CommandHandler.java:99)
        at org.subethamail.smtp.server.Session.runCommandLoop(Session.java:244)
        at org.subethamail.smtp.server.Session.run(Session.java:145)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
Caused by: org.alfresco.repo.search.impl.lucene.LuceneQueryParserException: 10304467 Request failed 400 /solr4/alfresco/alfresco?wt=json&fl=DBID%2Cscore&rows=1000&df=TEXT&start=0&locale=en_US&alternativeDic=DEFAULT_DICTIONARY&fq=%7B%21afts%7DAUTHORITY_FILTER_FROM_JSON&fq=%7B%21afts%7DTENANT_FILTER_FROM_JSON
        at org.alfresco.repo.search.impl.solr.SolrQueryHTTPClient.postQuery(SolrQueryHTTPClient.java:616)
        at org.alfresco.repo.search.impl.solr.SolrQueryHTTPClient.postSolrQuery(SolrQueryHTTPClient.java:559)
        at org.alfresco.repo.search.impl.solr.SolrQueryHTTPClient.executeQuery(SolrQueryHTTPClient.java:520)
        at org.alfresco.repo.search.impl.solr.SolrQueryLanguage.executeQuery(SolrQueryLanguage.java:51)
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

On the solr server:

ERROR [solr.core.SolrCore] [http-bio-8443-exec-10] org.apache.solr.common.SolrException: Invalid Number: <<Some string with letters>>
        at org.apache.solr.schema.TrieField.readableToIndexed(TrieField.java:406)
        at org.apache.solr.schema.TrieField.readableToIndexed(TrieField.java:378)
        at org.apache.solr.schema.TrieField.toInternal(TrieField.java:413)
        at org.apache.solr.schema.FieldType$DefaultAnalyzer$1.incrementToken(FieldType.java:473)
        at org.alfresco.solr.query.Solr4QueryParser.getFieldQueryImpl(Solr4QueryParser.java:1252)
        at org.alfresco.solr.query.Solr4QueryParser.getFieldQueryImplWithIOExceptionWrapped(Solr4QueryParser.java:812)
        at org.alfresco.solr.query.Solr4QueryParser.getSuperFieldQuery(Solr4QueryParser.java:3380)
        at org.alfresco.solr.query.Solr4QueryParser$FieldQuery.getQuery(Solr4QueryParser.java:3478)
        at org.alfresco.solr.query.Solr4QueryParser.attributeQueryBuilder(Solr4QueryParser.java:3894)
        at org.alfresco.solr.query.Solr4QueryParser.getFieldQuery(Solr4QueryParser.java:610)
        at org.alfresco.solr.query.Solr4QueryParser.getFieldQuery(Solr4QueryParser.java:459)
        at org.apache.lucene.queryparser.classic.QueryParserBase.handleBareTokenQuery(QueryParserBase.java:842)
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

[afaust]

Hello,

this errors is from the SMTP server of Alfresco, which attempts to resolve some nodes for processing where to store the mail. Most likely, this is related to user and alias resolution. Unfortunately, the SMTP server code does not perform transactional metadata queries and thus requires SOLR to be running (if SOLR is down, SMTP server will likely not work at all).
In the alfresco.log error you should typically be able to see a bit more detail, most relevant of which would be the actual query being executed (which is not present in the SOLR URL). Also a bit more of the stack trace would also help to pinpoint the exact cause even without the query.

Regards
Axel

[lothar]

Hi,
at my installation (also Alfresco 5.0) the same error occurs when an attempt for email sending is raised.
A related question is: how to check if the SOLR is correctly working?
My alfresco.log shows this (perhaps it helps):

2016-01-25 16:36:40,879 ERROR [org.springframework.extensions.surf.util.AbstractLifecycleBean] [org.subethamail.smtp.server.Session-/134.100.9.70:59088] 00250024 Email message processing failed
org.alfresco.error.AlfrescoRuntimeException: 00250024 Email message processing failed
   at org.alfresco.email.server.EmailServiceImpl.processMessage(EmailServiceImpl.java:324)
   at org.alfresco.email.server.EmailServiceImpl.importMessage(EmailServiceImpl.java:180)
   at org.alfresco.email.server.impl.subetha.SubethaEmailServer$Handler.processDelivery(SubethaEmailServer.java:223)
   at org.alfresco.email.server.impl.subetha.SubethaEmailServer$Handler.data(SubethaEmailServer.java:184)
   at org.subethamail.smtp.command.DataCommand.execute(DataCommand.java:64)
   at org.subethamail.smtp.server.RequireTLSCommandWrapper.execute(RequireTLSCommandWrapper.java:30)
   at org.subethamail.smtp.server.CommandHandler.handleCommand(CommandHandler.java:99)
   at org.subethamail.smtp.server.Session.runCommandLoop(Session.java:244)
   at org.subethamail.smtp.server.Session.run(Session.java:145)
   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   at java.lang.Thread.run(Thread.java:745)
Caused by: org.alfresco.repo.search.impl.lucene.LuceneQueryParserException: 00250023 Request failed 400 /solr4/alfresco/alfresco?wt=json&fl=DBID%2Cscore&rows=1000&df=TEXT&start=0&locale=de_DE&alternativeDic=DEFAULT_DICTIONARY&fq=%7B%21afts%7DAUTHORITY_FILTER_FROM_JSON&fq=%7B%21afts%7DTENANT_FILTER_FROM_JSON
   at org.alfresco.repo.search.impl.solr.SolrQueryHTTPClient.postQuery(SolrQueryHTTPClient.java:616)
   at org.alfresco.repo.search.impl.solr.SolrQueryHTTPClient.postSolrQuery(SolrQueryHTTPClient.java:559)
   at org.alfresco.repo.search.impl.solr.SolrQueryHTTPClient.executeQuery(SolrQueryHTTPClient.java:520)
   at org.alfresco.repo.search.impl.solr.SolrQueryLanguage.executeQuery(SolrQueryLanguage.java:51)
   at org.alfresco.repo.search.impl.solr.SolrSearchService.query(SolrSearchService.java:348)
   at org.alfresco.repo.search.impl.solr.SolrSearchService.query(SolrSearchService.java:152)
   at org.alfresco.repo.search.SearcherComponent.query(SearcherComponent.java:66)
   at org.alfresco.repo.search.AbstractSearcherComponent.query(AbstractSearcherComponent.java:53)
   at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
   at java.lang.reflect.Method.invoke(Method.java:483)
   at org.alfresco.repo.management.subsystems.SubsystemProxyFactory$1.invoke(SubsystemProxyFactory.java:72)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
   at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
   at com.sun.proxy.$Proxy20.query(Unknown Source)
   at org.alfresco.repo.search.impl.SearchServiceSubSystemDelegator.query(SearchServiceSubSystemDelegator.java:91)
   at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
   at java.lang.reflect.Method.invoke(Method.java:483)
   at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
   at net.sf.acegisecurity.intercept.method.aopalliance.MethodSecurityInterceptor.invoke(MethodSecurityInterceptor.java:80)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
   at org.alfresco.repo.security.permissions.impl.ExceptionTranslatorMethodInterceptor.invoke(ExceptionTranslatorMethodInterceptor.java:46)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
   at org.alfresco.repo.audit.AuditMethodInterceptor.invoke(AuditMethodInterceptor.java:159)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
   at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:96)
   at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:260)
   at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:94)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
   at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
   at com.sun.proxy.$Proxy20.query(Unknown Source)
   at org.alfresco.email.server.EmailServiceImpl.getTargetNode(EmailServiceImpl.java:451)
   at org.alfresco.email.server.EmailServiceImpl.access$500(EmailServiceImpl.java:63)
   at org.alfresco.email.server.EmailServiceImpl$3.execute(EmailServiceImpl.java:289)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:457)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:345)
   at org.alfresco.email.server.EmailServiceImpl$4.doWork(EmailServiceImpl.java:304)
   at org.alfresco.repo.security.authentication.AuthenticationUtil.runAs(AuthenticationUtil.java:548)
   at org.alfresco.email.server.EmailServiceImpl.processMessage(EmailServiceImpl.java:307)
   … 11 more


‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

Thank you,
l.