Otro system failure: ZimbraLdapContext pero al usar ZCS PST Import Wizard
Hola, mi configuracion es: Zimbra zcs-6.0.5_GA_2213.DEBIAN5.20100131173855, en una VMware 1.6 con Gues: GNU/Linux Debian 5.0 y Host: Windows 2003.
Hoy los molesto con un error que me pasa muy seguido, y la única solución que he encontrado es reiniciar Zimbra. o esperar al wachdog.
Si chequeo con zmcontrol me indica que esta corriendo todo. seguí los pasos LDAP - Zimbra :: Wiki [ara verificar el ldap, pero al estar corriendo el ldapd no hay mucho mas que se me ocura para ver.
Parece suceder aleatoriamente, pero lo puedo forzar realizando una importación con ZCSPSTImportWizard.
La verdad es que no se por donde orientar la búsqueda del error.. (capas q sea mejor reinstalar todo)
Viendo los log, estan los errores:
* "quillen saslauthd: auth_zimbra_init: zimbra_cert_check is off!" busque en interner y el certificado solo se usa en ssl imap (donde no es el caso)
* "com.zimbra.common.service.ServiceException: system failure: ZimbraLdapContext" es tan generico que es dificil encontrar como orientarce.
* las excepciones de java "Caused by: javax.naming.CommunicationException: Bad file descriptor [Root exception is java.net.SocketException: Bad file descriptor]" , "
Caused by: java.net.SocketException: Bad file descriptor " Son tan genéricas para mi, que al buscar en Internet se abren mucho las opciones de la posible razones. Lo que hace que uno solo de vueltas .
Agradeceré cualquier recomendación/orientación de que mirar, porque la verdad es que estoy pensado reinstalar todo, cosa que no me gusta ,uno no aprende reinstalando.. solo junta dudas…
Es algo del protocolo soap al pedir datos al servicio Ldap, pero no se que mas mirar proque aveces anda y otras no..
Gracias.
Les dejo los log justo cuando aparecio el problema al realizar la importacion, aproximadamente a las 2010-04-27 16:19:20,11
mailbox.log Code:
10-04-27 16:16:52,538 INFO [btpool0-18://correo.mydominio.com.ar:8031/service/soap/] [name=vkoenig@mydominio.com.ar;mid=34;ip=192.168.0.12;] mailop - Adding Message: id=11200, Message-ID=null, parentId=-1, folderId=5, folderName=Sent.
2010-04-27 16:16:52,885 INFO [btpool0-18://correo.mydominio.com.ar:8031/service/upload?fmt=raw] [name=vkoenig@mydominio.com.ar;mid=34;ip=192.168.0.12;ua=Zimbra Systems Client;] mailbox - FileUploadServlet received Upload: { accountId=e989163f-a973-490c-a0cb-05f33e99870e, time=Tue Apr 27 16:16:52 ART 2010, uploadId=ba064c54-4b4c-46d2-8625-6bf0177bfa7b:000baa5b-5b70-416e-944c-c49f0691295c, lslib32.bin}
2010-04-27 16:16:53,169 INFO [btpool0-18://correo.mydominio.com.ar:8031/service/soap/] [name=vkoenig@mydominio.com.ar;mid=34;ip=192.168.0.12;] soap - BatchRequest
2010-04-27 16:16:53,169 INFO [btpool0-18://correo.mydominio.com.ar:8031/service/soap/] [name=vkoenig@mydominio.com.ar;mid=34;ip=192.168.0.12;] soap - (batch) AddMsgRequest
2010-04-27 16:16:53,376 INFO [btpool0-18://correo.mydominio.com.ar:8031/service/soap/] [name=vkoenig@mydominio.com.ar;mid=34;ip=192.168.0.12;] mailop - Adding Message: id=11201, Message-ID=<E1O4bUC-0004DQ-Hi@corralon.mydominio.com.ar>, parentId=-1, folderId=3, folderName=Trash.
2010-04-27 16:17:50,113 INFO [Timer-Zimbra] [] FileUploadServlet - 1 pending file uploads
2010-04-27 16:18:01,328 INFO [btpool0-18://correo.mydominio.com.ar:8031/service/soap/SearchRequest] [name=vkoenig@mydominio.com.ar;mid=34;ip=192.168.0.12;ua=ZimbraWebClient - FF3.0 (Win)/6.0.5_GA_2213.DEBIAN5;] soap - SearchRequest
2010-04-27 16:18:01,332 INFO [btpool0-21://correo.mydominio.com.ar:8031/service/soap/SearchRequest] [name=vkoenig@mydominio.com.ar;mid=34;ip=192.168.0.12;ua=ZimbraWebClient - FF3.0 (Win)/6.0.5_GA_2213.DEBIAN5;] soap - SearchRequest
2010-04-27 16:18:03,734 INFO [btpool0-18://correo.mydominio.com.ar:8031/service/soap/SearchConvRequest] [name=vkoenig@mydominio.com.ar;mid=34;ip=192.168.0.12;ua=ZimbraWebClient - FF3.0 (Win)/6.0.5_GA_2213.DEBIAN5;] soap - SearchConvRequest
2010-04-27 16:18:50,113 INFO [Timer-Zimbra] [] FileUploadServlet - 1 pending file uploads
2010-04-27 16:19:20,119 INFO [btpool0-21://192.168.0.25:8031/service/soap/] [ip=192.168.0.74;ua=Zimbra Desktop/1.0.4_1833_Windows;] soap - AuthRequest
2010-04-27 16:19:20,123 INFO [btpool0-21://192.168.0.25:8031/service/soap/] [ip=192.168.0.74;ua=Zimbra Desktop/1.0.4_1833_Windows;] SoapEngine - handler exception
com.zimbra.common.service.ServiceException: system failure: ZimbraLdapContext
ExceptionId:btpool0-21://192.168.0.25:8031/service/soap/:1272395960123:9cc36b530f1a055a
Code:service.FAILURE
at com.zimbra.common.service.ServiceException.FAILURE(ServiceException.java:248)
at com.zimbra.cs.account.ldap.ZimbraLdapContext.<init>(ZimbraLdapContext.java:392)
at com.zimbra.cs.account.ldap.ZimbraLdapContext.<init>(ZimbraLdapContext.java:353)
at com.zimbra.cs.account.ldap.LdapProvisioning.getAccountByQuery(LdapProvisioning.java:584)
at com.zimbra.cs.account.ldap.LdapProvisioning.getAccountByNameInternal(LdapProvisioning.java:758)
at com.zimbra.cs.account.ldap.LdapProvisioning.getAccountByName(LdapProvisioning.java:736)
at com.zimbra.cs.account.ldap.LdapProvisioning.get(LdapProvisioning.java:644)
at com.zimbra.cs.account.ldap.LdapProvisioning.get(LdapProvisioning.java:629)
at com.zimbra.cs.service.account.Auth.handle(Auth.java:98)
at com.zimbra.soap.SoapEngine.dispatchRequest(SoapEngine.java:419)
at com.zimbra.soap.SoapEngine.dispatch(SoapEngine.java:273)
at com.zimbra.soap.SoapEngine.dispatch(SoapEngine.java:157)
at com.zimbra.soap.SoapServlet.doWork(SoapServlet.java:291)
at com.zimbra.soap.SoapServlet.doPost(SoapServlet.java:212)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)
at com.zimbra.cs.servlet.ZimbraServlet.service(ZimbraServlet.java:181)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:511)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1166)
at com.zimbra.cs.servlet.SetHeaderFilter.doFilter(SetHeaderFilter.java:79)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
at org.mortbay.servlet.UserAgentFilter.doFilter(UserAgentFilter.java:81)
at org.mortbay.servlet.GzipFilter.doFilter(GzipFilter.java:155)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:388)
at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)
at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.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(HandlerWrapper.java:152)
at org.mortbay.jetty.handler.rewrite.RewriteHandler.handle(RewriteHandler.java:230)
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
at org.mortbay.jetty.handler.DebugHandler.handle(DebugHandler.java:77)
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
at org.mortbay.jetty.Server.handle(Server.java:326)
at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:543)
at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:939)
at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:755)
at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:218)
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:405)
at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:409)
at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:451)
Caused by: javax.naming.CommunicationException [Root exception is java.net.SocketException: Socket closed]
at com.sun.jndi.ldap.LdapClient.authenticate(LdapClient.java:139)
at com.sun.jndi.ldap.LdapCtx.connect(LdapCtx.java:2694)
at com.sun.jndi.ldap.LdapCtx.<init>(LdapCtx.java:293)
at com.sun.jndi.ldap.LdapCtxFactory.getUsingURL(LdapCtxFactory.java:175)
at com.sun.jndi.ldap.LdapCtxFactory.getUsingURLs(LdapCtxFactory.java:193)
at com.sun.jndi.ldap.LdapCtxFactory.getLdapCtxInstance(LdapCtxFactory.java:136)
at com.sun.jndi.ldap.LdapCtxFactory.getInitialContext(LdapCtxFactory.java:66)
at javax.naming.spi.NamingManager.getInitialContext(NamingManager.java:667)
at javax.naming.InitialContext.getDefaultInitCtx(InitialContext.java:288)
at javax.naming.InitialContext.init(InitialContext.java:223)
at javax.naming.ldap.InitialLdapContext.<init>(InitialLdapContext.java:134)
at com.zimbra.cs.account.ldap.ZimbraLdapContext.<init>(ZimbraLdapContext.java:378)
... 42 more
Caused by: java.net.SocketException: Socket closed
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
at java.io.BufferedInputStream.read1(BufferedInputStream.java:258)
at java.io.BufferedInputStream.read(BufferedInputStream.java:317)
at com.sun.jndi.ldap.Connection.run(Connection.java:805)
at java.lang.Thread.run(Thread.java:619)
2010-04-27 16:19:22,844 INFO [btpool0-18://192.168.0.25:8031/service/soap/] [ip=192.168.0.74;ua=Zimbra Desktop/1.0.4_1833_Windows;] soap - AuthRequest
2010-04-27 16:19:22,846 INFO [btpool0-18://192.168.0.25:8031/service/soap/] [ip=192.168.0.74;ua=Zimbra Desktop/1.0.4_1833_Windows;] SoapEngine - handler exception
com.zimbra.common.service.ServiceException: system failure: ZimbraLdapContext
ExceptionId:btpool0-18://192.168.0.25:8031/service/soap/:1272395962846:9cc36b530f1a055a
Code:service.FAILURE
at com.zimbra.common.service.ServiceException.FAILURE(ServiceException.java:248)
at com.zimbra.cs.account.ldap.ZimbraLdapContext.<init>(ZimbraLdapContext.java:392)
at com.zimbra.cs.account.ldap.ZimbraLdapContext.<init>(ZimbraLdapContext.java:353)
at com.zimbra.cs.account.ldap.LdapProvisioning.getAccountByQuery(LdapProvisioning.java:584)
at com.zimbra.cs.account.ldap.LdapProvisioning.getAccountById(LdapProvisioning.java:616)
audit.log Code:
2010-04-27 15:49:45,362 INFO [btpool0-18://correo.mydominio.com.ar:8031/service/soap/] [name=vkoenig@mydominio.com.ar;ip=192.168.0.12;] security - cmd=Auth; account=vkoenig@mydominio.com.ar; protocol=soap;
2010-04-27 15:50:22,195 INFO [btpool0-17://localhost:7071/service/admin/soap/AuthRequest] [name=zimbra;ip=127.0.0.1;] security - cmd=AdminAuth; account=zimbra;
2010-04-27 15:50:22,195 INFO [btpool0-17://localhost:7071/service/admin/soap/AuthRequest] [name=zimbra;ip=127.0.0.1;] security - cmd=Auth; account=zimbra; protocol=soap;
2010-04-27 15:53:24,600 INFO [btpool0-18://correo.mydominio.com.ar:8031/service/soap/] [name=vkoenig@mydominio.com.ar;ip=192.168.0.12;] security - cmd=Auth; account=vkoenig@mydominio.com.ar; protocol=soap;
2010-04-27 16:00:14,249 INFO [btpool0-19://localhost:7071/service/admin/soap/AuthRequest] [name=zimbra;ip=127.0.0.1;] security - cmd=AdminAuth; account=zimbra;
2010-04-27 16:00:14,249 INFO [btpool0-19://localhost:7071/service/admin/soap/AuthRequest] [name=zimbra;ip=127.0.0.1;] security - cmd=Auth; account=zimbra; protocol=soap;
2010-04-27 16:10:27,618 WARN [btpool0-18://localhost:7071/service/admin/soap/AuthRequest] [ip=127.0.0.1;] security - cmd=AdminAuth; account=zimbra; error=system failure: ZimbraLdapContext;
2010-04-27 16:20:27,891 WARN [btpool0-21://localhost:7071/service/admin/soap/AuthRequest] [ip=127.0.0.1;] security - cmd=AdminAuth; account=zimbra; error=system failure: ZimbraLdapContext;
2010-04-27 16:30:12,992 INFO [btpool0-21://localhost:7071/service/admin/soap/AuthRequest] [name=zimbra;ip=127.0.0.1;] security - cmd=AdminAuth; account=zimbra;
2010-04-27 16:30:12,993 INFO [btpool0-21://localhost:7071/service/admin/soap/AuthRequest] [name=zimbra;ip=127.0.0.1;] security - cmd=Auth; account=zimbra; protocol=soap;
2010-04-27 16:40:12,421 INFO [btpool0-18://localhost:7071/service/admin/soap/AuthRequest] [name=zimbra;ip=127.0.0.1;] security - cmd=AdminAuth; account=zimbra;
2010-04-27 16:40:12,422 INFO [btpool0-18://localhost:7071/service/admin/soap/AuthRequest] [name=zimbra;ip=127.0.0.1;] security - cmd=Auth; account=zimbra; protocol=soap;
2010-04-27 16:50:15,495 INFO [btpool0-18://localhost:7071/service/admin/soap/AuthRequest] [name=zimbra;ip=127.0.0.1;] security - cmd=AdminAuth; account=zimbra;
2010-04-27 16:50:15,495 INFO [btpool0-18://localhost:7071/service/admin/soap/AuthRequest] [name=zimbra;ip=127.0.0.1;] security - cmd=Auth; account=zimbra; protocol=soap;
messages
Code:
Apr 25 07:37:51 quillen kernel: imklog 3.18.6, log source = /proc/kmsg started.
Apr 25 07:37:51 quillen rsyslogd: [origin software="rsyslogd" swVersion="3.18.6" x-pid="2028" x-info="http://www.rsyslog.com"] restart
Apr 26 07:37:43 quillen kernel: imklog 3.18.6, log source = /proc/kmsg started.
Apr 26 07:37:43 quillen rsyslogd: [origin software="rsyslogd" swVersion="3.18.6" x-pid="2028" x-info="http://www.rsyslog.com"] restart
Apr 26 07:37:52 quillen kernel: [498784.183892] swatch[29062]: segfault at 65c ip 080c4d26 sp bf80a140 error 4 in perl[8048000+12b000]
Apr 26 14:46:57 quillen saslauthd: auth_zimbra_init: zimbra_cert_check is off!
Apr 26 14:46:57 quillen saslauthd: auth_zimbra_init: 1 auth urls initialized for round-robin
Apr 26 15:49:41 quillen saslauthd: auth_zimbra_init: zimbra_cert_check is off!
Apr 26 15:49:41 quillen saslauthd: auth_zimbra_init: 1 auth urls initialized for round-robin
Apr 27 07:37:29 quillen kernel: Kernel logging (proc) stopped.
Apr 27 07:37:29 quillen kernel: imklog 3.18.6, log source = /proc/kmsg started.
Apr 27 07:37:29 quillen rsyslogd: [origin software="rsyslogd" swVersion="3.18.6" x-pid="2028" x-info="http://www.rsyslog.com"] restart
Apr 27 14:13:02 quillen saslauthd: auth_zimbra_init: zimbra_cert_check is off!
Apr 27 14:13:02 quillen saslauthd: auth_zimbra_init: 1 auth urls initialized for round-robin
Apr 28 07:39:21 quillen kernel: imklog 3.18.6, log source = /proc/kmsg started.
Apr 28 07:39:21 quillen rsyslogd: [origin software="rsyslogd" swVersion="3.18.6" x-pid="2028" x-info="http://www.rsyslog.com"] restart
zimbra.log
Code:
Apr 27 16:15:01 quillen zmmailboxdmgr[21949]: status OK
Apr 27 16:15:03 quillen zmmailboxdmgr[22019]: status requested
Apr 27 16:15:03 quillen zmmailboxdmgr[22019]: status OK
Apr 27 16:16:22 quillen zmmailboxdmgr[22994]: status requested
Apr 27 16:16:22 quillen zmmailboxdmgr[22994]: status OK
Apr 27 16:16:59 quillen zmmailboxdmgr[23833]: status requested
Apr 27 16:16:59 quillen zmmailboxdmgr[23833]: status OK
Apr 27 16:17:00 quillen zmmailboxdmgr[23891]: status requested
Apr 27 16:17:00 quillen zmmailboxdmgr[23891]: status OK
Apr 27 16:18:24 quillen zmmailboxdmgr[24616]: status requested
Apr 27 16:18:24 quillen zmmailboxdmgr[24616]: status OK
Apr 27 16:18:50 quillen zmmailboxdmgr[25322]: status requested
Apr 27 16:18:50 quillen zmmailboxdmgr[25322]: status OK
Apr 27 16:18:51 quillen zmmailboxdmgr[25380]: status requested
Apr 27 16:18:51 quillen zmmailboxdmgr[25380]: status OK
Apr 27 16:20:02 quillen zimbramon[25735]: 25735:info: 2010-04-27 16:20:02, QUEUE: 0 0
Apr 27 16:20:04 quillen clamd[2902]: SelfCheck: Database modification detected. Forcing reload.
Apr 27 16:20:06 quillen clamd[2902]: Reading databases from /opt/zimbra/data/clamav/db
Apr 27 16:20:23 quillen clamd[2902]: Database correctly reloaded (758179 signatures)
Apr 27 16:20:32 quillen zmmailboxdmgr[26465]: status requested
Apr 27 16:20:32 quillen zmmailboxdmgr[26465]: status OK
Apr 27 16:20:50 quillen zmmailboxdmgr[26928]: status requested
Apr 27 16:20:50 quillen zmmailboxdmgr[26928]: status OK
Apr 27 16:20:51 quillen zmmailboxdmgr[26986]: status requested
Apr 27 16:20:51 quillen zmmailboxdmgr[26986]: status OK
Apr 27 16:22:19 quillen zmmailboxdmgr[27848]: status requested
Apr 27 16:22:19 quillen zmmailboxdmgr[27848]: status OK
Apr 27 16:22:38 quillen zmmailboxdmgr[28354]: status requested
Apr 27 16:22:38 quillen zmmailboxdmgr[28354]: status OK
Apr 27 16:22:39 quillen zmmailboxdmgr[28412]: status requested
