ZCS can not access zimbra account via POP

[pmona]

I have multiple zimbra accounts which I have set up as external accounts on my main email. This allows me to pull email from all my accounts with just the one login. I use POP3 to access these accounts. One of them, (5 others continue to work without issue), began failing last night with this error:

account "CPWConnect" Failed
--------------------------------------------------------------------------------
system failure: Unable to connect to POP3 server: DataSource: { id=595556fc-6c87-4313-b97d-f9747d95a9a0, type=pop3, isEnabled=false, name=CPWConnect, host=mydomain.com, port=995, connectionType=ssl, username=CPWConnect, folderId=1014 }, Invalid STAT response: 113631 2166837977


[zimbra@zimbra ~]$ zmcontrol -v

Release 6.0.7_GA_2473.RHEL5_20100616214455 CentOS5 FOSS edition.



I see the following in my mailbox.log file:


2010-09-30 06:23:10,581 INFO [btpool0-489://mydomain.com:8010/service/soap/ImportDataRequest] [name=mainUser@mydomain.com;mid=4;ip=172.20.1.100;u a=ZimbraWebClient - FF3.0 (Win)/6.0.7_GA_2473.RHEL5;ds=CPWConnect;] SoapEngine - handler exception
com.zimbra.common.service.ServiceException: system failure: Unable to connect to POP3 server: DataSource: { id=595556fc-6c87-4313-b97d-f9747d95a9a0, type=pop3, isEnabled=false, name=CPWConnect, host=mydomain.com, port=995, connectionType=ssl, username=commpartners, folderId=1014 }
2010-09-30 07:03:18,409 INFO [btpool0-495://mydomain.com:8010/service/soap/ImportDataRequest] [name=mainUser@mydomain.com;mid=4;ip=172.20.1.100;u a=ZimbraWebClient - FF3.0 (Win)/6.0.7_GA_2473.RHEL5;ds=CPWConnect;] datasource - Importing data for data source 'CPWConnect'
2010-09-30 07:03:20,529 INFO [btpool0-495://mydomain.com:8010/service/soap/ImportDataRequest] [name=mainUser@mydomain.com;mid=4;ip=172.20.1.100;u a=ZimbraWebClient - FF3.0 (Win)/6.0.7_GA_2473.RHEL5;ds=CPWConnect;] datasource - Import completed for data source 'CPWConnect'
2010-09-30 07:03:20,530 INFO [btpool0-495://mydomain.com:8010/service/soap/ImportDataRequest] [name=mainUser@mydomain.com;mid=4;ip=172.20.1.100;u a=ZimbraWebClient - FF3.0 (Win)/6.0.7_GA_2473.RHEL5;ds=CPWConnect;] SoapEngine - handler exception
com.zimbra.common.service.ServiceException: system failure: Unable to connect to POP3 server: DataSource: { id=595556fc-6c87-4313-b97d-f9747d95a9a0, type=pop3, isEnabled=false, name=CPWConnect, host=mydomain.com, port=995, connectionType=ssl, username=commpartners, folderId=1014 }
2010-09-30 10:46:52,125 INFO [btpool0-12://mydomain.com:8010/service/soap/ImportDataRequest] [name=mainUser@mydomain.com;mid=4;ip=204.14.39.130; ua=ZimbraWebClient - FF3.0 (Win)/6.0.7_GA_2473.RHEL5;ds=CPWConnect;] datasource - Importing data for data source 'CPWConnect'
2010-09-30 10:46:54,851 INFO [btpool0-12://mydomain.com:8010/service/soap/ImportDataRequest] [name=mainUser@mydomain.com;mid=4;ip=204.14.39.130; ua=ZimbraWebClient - FF3.0 (Win)/6.0.7_GA_2473.RHEL5;ds=CPWConnect;] datasource - Import completed for data source 'CPWConnect'
2010-09-30 10:46:54,856 INFO [btpool0-12://mydomain.com:8010/service/soap/ImportDataRequest] [name=mainUser@mydomain.com;mid=4;ip=204.14.39.130; ua=ZimbraWebClient - FF3.0 (Win)/6.0.7_GA_2473.RHEL5;ds=CPWConnect;] SoapEngine - handler exception
com.zimbra.common.service.ServiceException: system failure: Unable to connect to POP3 server: DataSource: { id=595556fc-6c87-4313-b97d-f9747d95a9a0, type=pop3, isEnabled=false, name=CPWConnect, host=mydomain.com, port=995, connectionType=ssl, username=commpartners, folderId=1014 }

[pmona]

I posted two follow ups a couple of days ago, but for some reason they no longer appear in the thread.

I have since tested POP access using Outlook and it works fine. Only ZCS has a problem accessing this account using POP. The other zimbra accounts I access via POP continue to work without issue also.

Here is additional log output when an attempt is made to access the account via ZCS:

2010-10-03 08:50:49,031 INFO [btpool0-22://mydomain.com:8010/service/soap/SearchRequest] [name=mainUser@mydomain.com;mid=4;ip=172.20.1.100;u a=ZimbraWebClient - FF3.0 (Win)/6.0.7_GA_2473.RHEL5;] soap - SearchRequest
2010-10-03 08:50:50,497 INFO [btpool0-22://mydomain.com:8010/service/soap/ImportDataRequest] [name=mainUser@mydomain.com;mid=4;ip=172.20.1.100;u a=ZimbraWebClient - FF3.0 (Win)/6.0.7_GA_2473.RHEL5;] soap - ImportDataRequest
2010-10-03 08:50:50,508 INFO [btpool0-22://mydomain.com:8010/service/soap/ImportDataRequest] [name=mainUser@mydomain.com;mid=4;ip=172.20.1.100;u a=ZimbraWebClient - FF3.0 (Win)/6.0.7_GA_2473.RHEL5;ds=CPWConnect;] datasource - Importing data for data source 'CPWConnect'
2010-10-03 08:50:50,577 INFO [Pop3SSLServer-8] [ip=172.20.1.4;] pop - connected
2010-10-03 08:50:50,620 INFO [Pop3SSLServer-8] [name=CPWConnect@mydomain.com;ip=172.20.1.4;] pop - user CPWConnect@mydomain.com authenticated, mechanism=LOGIN [TLS]
2010-10-03 08:50:51,965 INFO [Pop3SSLServer-8] [name=CPWConnect@mydomain.com;ip=172.20.1.4;] pop - disconnected without quit
2010-10-03 08:50:51,965 INFO [Pop3SSLServer-8] [] ProtocolHandler - Handler exiting normally
2010-10-03 08:50:52,113 INFO [btpool0-22://mydomain.com:8010/service/soap/ImportDataRequest] [name=mainUser@mydomain.com;mid=4;ip=172.20.1.100;u a=ZimbraWebClient - FF3.0 (Win)/6.0.7_GA_2473.RHEL5;ds=CPWConnect;] datasource - Import completed for data source 'CPWConnect'
2010-10-03 08:50:52,114 INFO [btpool0-22://mydomain.com:8010/service/soap/ImportDataRequest] [name=mainUser@mydomain.com;mid=4;ip=172.20.1.100;u a=ZimbraWebClient - FF3.0 (Win)/6.0.7_GA_2473.RHEL5;ds=CPWConnect;] SoapEngine - handler exception
com.zimbra.common.service.ServiceException: system failure: Unable to connect to POP3 server: DataSource: { id=595556fc-6c87-4313-b97d-f9747d95a9a0, type=pop3, isEnabled=false, name=CPWConnect, host=mydomain.com, port=995, connectionType=ssl, username=CPWConnect, folderId=1014 }
ExceptionId:btpool0-22://mydomain.com:8010/service/soap/ImportDataRequest:1286121051961:d9e1bf8ccba2ebfc
Code:service.FAILURE
at com.zimbra.common.service.ServiceException.FAILURE (ServiceException.java:248)
at com.zimbra.cs.datasource.Pop3Sync.connect(Pop3Sync .java:165)
at com.zimbra.cs.datasource.Pop3Sync.importData(Pop3S ync.java:134)
at com.zimbra.cs.datasource.DataSourceManager.importD ata(DataSourceManager.java:254)
at com.zimbra.cs.datasource.DataSourceManager.importD ata(DataSourceManager.java:214)
at com.zimbra.cs.service.mail.ImportData.handle(Impor tData.java:60)
at com.zimbra.soap.SoapEngine.dispatchRequest(SoapEng ine.java:420)
at com.zimbra.soap.SoapEngine.dispatch(SoapEngine.jav a:274)
at com.zimbra.soap.SoapEngine.dispatch(SoapEngine.jav a:158)
at com.zimbra.soap.SoapServlet.doWork(SoapServlet.jav a:291)
at com.zimbra.soap.SoapServlet.doPost(SoapServlet.jav a:212)
at javax.servlet.http.HttpServlet.service(HttpServlet .java:727)
at com.zimbra.cs.servlet.ZimbraServlet.service(Zimbra Servlet.java:181)
at javax.servlet.http.HttpServlet.service(HttpServlet .java:820)
at org.mortbay.jetty.servlet.ServletHolder.handle(Ser vletHolder.java:511)
at org.mortbay.jetty.servlet.ServletHandler$CachedCha in.doFilter(ServletHandler.java:1166)
at com.zimbra.cs.servlet.SetHeaderFilter.doFilter(Set HeaderFilter.java:79)
at org.mortbay.jetty.servlet.ServletHandler$CachedCha in.doFilter(ServletHandler.java:1157)
at org.mortbay.servlet.UserAgentFilter.doFilter(UserA gentFilter.java:81)
at org.mortbay.servlet.GzipFilter.doFilter(GzipFilter .java:132)
at org.mortbay.jetty.servlet.ServletHandler$CachedCha in.doFilter(ServletHandler.java:1157)
at org.mortbay.jetty.servlet.ServletHandler.handle(Se rvletHandler.java:388)
at org.mortbay.jetty.security.SecurityHandler.handle( SecurityHandler.java:216)
at org.mortbay.jetty.servlet.SessionHandler.handle(Se ssionHandler.java:182)
at org.mortbay.jetty.handler.ContextHandler.handle(Co ntextHandler.java:765)
at org.mortbay.jetty.webapp.WebAppContext.handle(WebA ppContext.java:418)
at org.mortbay.jetty.handler.ContextHandlerCollection .handle(ContextHandlerCollection.java:230)
at org.mortbay.jetty.handler.HandlerCollection.handle (HandlerCollection.java:114)
at org.mortbay.jetty.handler.HandlerWrapper.handle(Ha ndlerWrapper.java:152)
at org.mortbay.jetty.handler.rewrite.RewriteHandler.h andle(RewriteHandler.java:230)
at org.mortbay.jetty.handler.HandlerWrapper.handle(Ha ndlerWrapper.java:152)
at org.mortbay.jetty.handler.DebugHandler.handle(Debu gHandler.java:77)
at org.mortbay.jetty.handler.HandlerWrapper.handle(Ha ndlerWrapper.java:152)
at org.mortbay.jetty.Server.handle(Server.java:326)
at org.mortbay.jetty.HttpConnection.handleRequest(Htt pConnection.java:543)
at org.mortbay.jetty.HttpConnection$RequestHandler.co ntent(HttpConnection.java:939)
at org.mortbay.jetty.HttpParser.parseNext(HttpParser. java:755)
at org.mortbay.jetty.HttpParser.parseAvailable(HttpPa rser.java:218)
at org.mortbay.jetty.HttpConnection.handle(HttpConnec tion.java:405)
at org.mortbay.io.nio.SelectChannelEndPoint.run(Selec tChannelEndPoint.java:409)
at org.mortbay.thread.BoundedThreadPool$PoolThread.ru n(BoundedThreadPool.java:451)
Caused by: javax.security.auth.login.LoginException: Invalid STAT response: 115285 2185958355
at com.zimbra.cs.datasource.Pop3Sync.connect(Pop3Sync .java:161)
... 39 more
2010-10-03 08:50:56,417 INFO [btpool0-22://mydomain.com:8010/service/soap/GetImportStatusRequest] [name=mainUser@mydomain.com;mid=4;ip=172.20.1.100;u a=ZimbraWebClient - FF3.0 (Win)/6.0.7_GA_2473.RHEL5;] soap - GetImportStatusRequest

[pmona]

Does anybody have any idea how to resolve this problem. What should the next steps be?

I'm guessing since there have been no responses this is something that has never come up before.

[phoenix]

Originally Posted by pmona

I'm guessing since there have been no responses this is something that has never come up before.

It could also mean that it's already been answered, see if this applies to your problem: site:zimbra.com "system failure: Unable to connect to POP3 server: DataSource" - Yahoo! Search Results

[pmona]

Originally Posted by phoenix

It could also mean that it's already been answered, see if this applies to your problem: site:zimbra.com "system failure: Unable to connect to POP3 server: DataSource" - Yahoo! Search Results

Thank you, I have searched the forums already, including theses posts. None of the suggested solutions have resolved the issue.

I don't know if it makes a difference or not, but the ZCS box and the server the POP account is on are one in the same. I do this so I can have a single log on for email and access all my accounts on the Zimbra server. Why one out of more than 5 would encounter this problem after more than a year of service has me baffled.

[pmona]

As a last ditch effort, I upgraded to 6.0.8_GA_2661 but no change in behavior. POP access via ZCS still does not work and returns the same log messages.

Can anyone tell me what else I should look at? Is there anything in these log messages that points to the problem?

[pmona]

It makes no sense that only ZCS has a problem connecting to this account via POP. From the ZCS server itself, I can log in via the shell:

[root@zimbra ~]# telnet mydomain.com 110
Trying 172.20.1.4...
Connected to mydomain.com (172.20.1.4).
Escape character is '^]'.
+OK zimbra.mydomain.com Zimbra POP3 server ready
user CPWConnect@mydomain.com
+OK hello CPWConnect@mydomain.com, please enter your password
pass password
+OK server ready


But when ZCS attempts to access the account, it always fails. Same log as above, but I changed from using 995 to 110 to keep everything consistant:


2010-10-11 15:45:51,362 INFO [btpool0-47://mydomain.com:8043/zimbra/public/secureRequest.jsp] [name=mainUser@mydomain.com;mid=4;ip=204.14.39.130; ua=ZimbraWebClient - FF3.0 (Win)/6.0.8_GA_2661;] soap - TestDataSourceRequest
2010-10-11 15:45:51,363 INFO [btpool0-47://mydomain.com:8043/zimbra/public/secureRequest.jsp] [name=mainUser@mydomain.com;mid=4;ip=204.14.39.130; ua=ZimbraWebClient - FF3.0 (Win)/6.0.8_GA_2661;] datasource - Testing: DataSource: { id=TestId, type=pop3, isEnabled=false, name=Test, host=mydomain.com, port=110, connectionType=cleartext, username=CPWConnect, folderId=-1 }
2010-10-11 15:45:51,365 INFO [Pop3Server-66] [ip=172.20.1.4;] pop - connected
2010-10-11 15:45:51,373 INFO [Pop3Server-66] [name=CPWConnect@mydomain.com;ip=172.20.1.4;] pop - user CPWConnect@mydomain.com authenticated, mechanism=LOGIN
2010-10-11 15:45:52,631 WARN [btpool0-47://mydomain.com:8043/zimbra/public/secureRequest.jsp] [name=mainUser@mydomain.com;mid=4;ip=204.14.39.130; ua=ZimbraWebClient - FF3.0 (Win)/6.0.8_GA_2661;] datasource - Test failed: DataSource: { id=TestId, type=pop3, isEnabled=false, name=Test, host=mydomain.com, port=110, connectionType=cleartext, username=CPWConnect, folderId=-1 }
com.zimbra.common.service.ServiceException: system failure: Unable to connect to POP3 server: DataSource: { id=TestId, type=pop3, isEnabled=false, name=Test, host=mydomain.com, port=110, connectionType=cleartext, username=CPWConnect, folderId=-1 }
ExceptionId:btpool0-47://mydomain.com:8043/zimbra/public/secureRequest.jsp:1286837152631:9922e95c86399c45
Code:service.FAILURE
at com.zimbra.common.service.ServiceException.FAILURE (ServiceException.java:248)
at com.zimbra.cs.datasource.Pop3Sync.connect(Pop3Sync .java:167)
at com.zimbra.cs.datasource.Pop3Sync.test(Pop3Sync.ja va:110)
at com.zimbra.cs.datasource.DataSourceManager.test(Da taSourceManager.java:176)
at com.zimbra.cs.service.mail.TestDataSource.handle(T estDataSource.java:129)
at com.zimbra.soap.SoapEngine.dispatchRequest(SoapEng ine.java:420)
at com.zimbra.soap.SoapEngine.dispatch(SoapEngine.jav a:274)
at com.zimbra.soap.SoapEngine.dispatch(SoapEngine.jav a:158)
at com.zimbra.soap.SoapServlet.doWork(SoapServlet.jav a:291)
at com.zimbra.soap.SoapServlet.doPost(SoapServlet.jav a:212)
at javax.servlet.http.HttpServlet.service(HttpServlet .java:727)
at com.zimbra.cs.servlet.ZimbraServlet.service(Zimbra Servlet.java:181)
at javax.servlet.http.HttpServlet.service(HttpServlet .java:820)
at org.mortbay.jetty.servlet.ServletHolder.handle(Ser vletHolder.java:511)
at org.mortbay.jetty.servlet.ServletHandler.handle(Se rvletHandler.java:390)
at org.mortbay.jetty.security.SecurityHandler.handle( SecurityHandler.java:216)
at org.mortbay.jetty.servlet.SessionHandler.handle(Se ssionHandler.java:182)
at org.mortbay.jetty.handler.ContextHandler.handle(Co ntextHandler.java:765)
at org.mortbay.jetty.webapp.WebAppContext.handle(WebA ppContext.java:418)
at org.mortbay.jetty.servlet.Dispatcher.include(Dispa tcher.java:195)
at org.apache.jsp.public_.secureRequest_jsp._jspServi ce(secureRequest_jsp.java:258)
at org.apache.jasper.runtime.HttpJspBase.service(Http JspBase.java:109)
at javax.servlet.http.HttpServlet.service(HttpServlet .java:820)
at org.apache.jasper.servlet.JspServletWrapper.servic e(JspServletWrapper.java:389)
at org.apache.jasper.servlet.JspServlet.serviceJspFil e(JspServlet.java:486)
at org.apache.jasper.servlet.JspServlet.service(JspSe rvlet.java:380)
at javax.servlet.http.HttpServlet.service(HttpServlet .java:820)
at com.zimbra.webClient.servlet.JspServlet.service(Js pServlet.java:64)
at org.mortbay.jetty.servlet.ServletHolder.handle(Ser vletHolder.java:511)
at org.mortbay.jetty.servlet.ServletHandler$CachedCha in.doFilter(ServletHandler.java:1166)
at com.zimbra.cs.servlet.SetHeaderFilter.doFilter(Set HeaderFilter.java:79)
at com.zimbra.webClient.filters.SetHeaderFilter.doFil ter(SetHeaderFilter.java:241)
at org.mortbay.jetty.servlet.ServletHandler$CachedCha in.doFilter(ServletHandler.java:1157)
at org.mortbay.servlet.UserAgentFilter.doFilter(UserA gentFilter.java:81)
at org.mortbay.servlet.GzipFilter.doFilter(GzipFilter .java:132)
at org.mortbay.jetty.servlet.ServletHandler$CachedCha in.doFilter(ServletHandler.java:1157)
at org.mortbay.jetty.servlet.ServletHandler.handle(Se rvletHandler.java:388)
at org.mortbay.jetty.security.SecurityHandler.handle( SecurityHandler.java:216)
at org.mortbay.jetty.servlet.SessionHandler.handle(Se ssionHandler.java:182)
at org.mortbay.jetty.handler.ContextHandler.handle(Co ntextHandler.java:765)
at org.mortbay.jetty.webapp.WebAppContext.handle(WebA ppContext.java:418)
at org.mortbay.jetty.handler.ContextHandlerCollection .handle(ContextHandlerCollection.java:230)
at org.mortbay.jetty.handler.HandlerCollection.handle (HandlerCollection.java:114)
at org.mortbay.jetty.handler.HandlerWrapper.handle(Ha ndlerWrapper.java:152)
at org.mortbay.jetty.handler.rewrite.RewriteHandler.h andle(RewriteHandler.java:230)
at org.mortbay.jetty.handler.HandlerWrapper.handle(Ha ndlerWrapper.java:152)
at org.mortbay.jetty.handler.DebugHandler.handle(Debu gHandler.java:77)
at org.mortbay.jetty.handler.HandlerWrapper.handle(Ha ndlerWrapper.java:152)
at org.mortbay.jetty.Server.handle(Server.java:326)
at org.mortbay.jetty.HttpConnection.handleRequest(Htt pConnection.java:543)
at org.mortbay.jetty.HttpConnection$RequestHandler.co ntent(HttpConnection.java:939)
at org.mortbay.jetty.HttpParser.parseNext(HttpParser. java:755)
at org.mortbay.jetty.HttpParser.parseAvailable(HttpPa rser.java:218)
at org.mortbay.jetty.HttpConnection.handle(HttpConnec tion.java:405)
at org.mortbay.io.nio.SelectChannelEndPoint.run(Selec tChannelEndPoint.java:413)
at org.mortbay.thread.BoundedThreadPool$PoolThread.ru n(BoundedThreadPool.java:451)
Caused by: javax.security.auth.login.LoginException: Invalid STAT response: 121417 2264929003
at com.zimbra.cs.datasource.Pop3Sync.connect(Pop3Sync .java:163)
... 54 more
2010-10-11 15:45:52,638 INFO [Pop3Server-66] [name=CPWConnect@mydomain.com;ip=172.20.1.4;] pop - disconnected without quit
2010-10-11 15:45:52,638 INFO [Pop3Server-66] [] ProtocolHandler - Handler exiting normally
2010-10-11 15:45:54,287 INFO [MailboxPurge] [name=bulkmail@mydomain.com;mid=6;] purge - Purging messages.
2010-10-11 15:45:54,558 INFO [MailboxPurge] [name=bulkmail@mydomain.com;mid=6;] purge - Closed 1 conversations dated before 1284158754.
2010-10-11 15:46:00,042 INFO [btpool0-47://mydomain.com:8043/zimbra/public/secureRequest.jsp] [name=mainUser@mydomain.com;mid=4;ip=204.14.39.130; ua=ZimbraWebClient - FF3.0 (Win)/6.0.8_GA_2661;] soap - BatchRequest
2010-10-11 15:46:00,042 INFO [btpool0-47://mydomain.com:8043/zimbra/public/secureRequest.jsp] [name=mainUser@mydomain.com;mid=4;ip=204.14.39.130; ua=ZimbraWebClient - FF3.0 (Win)/6.0.8_GA_2661;] soap - (batch) ModifyDataSourceRequest
2010-10-11 15:46:00,322 INFO [btpool0-47://mydomain.com:8043/zimbra/public/secureRequest.jsp] [name=mainUser@mydomain.com;mid=4;ip=204.14.39.130; ua=ZimbraWebClient - FF3.0 (Win)/6.0.8_GA_2661;] datasource - Data source 7065cb5a-bc31-4161-9191-d4389e9480db is disabled. Deleting scheduled task.
2010-10-11 15:46:00,378 INFO [btpool0-47://mydomain.com:8043/zimbra/public/secureRequest.jsp] [name=mainUser@mydomain.com;mid=4;ip=204.14.39.130; ua=ZimbraWebClient - FF3.0 (Win)/6.0.8_GA_2661;] soap - (batch) NoOpRequest
2010-10-11 15:46:02,629 INFO [btpool0-47://zimbra.mydomain.com:7071/service/admin/soap/NoOpRequest] [name=admin@mydomain.com;mid=1;ip=10.10.10.75;ua=Zi mbraWebClient - FF3.0 (Win);] soap - NoOpRequest