Results 1 to 5 of 5

Thread: Server connection failure during transaction

  1. #1
    Join Date
    Jul 2008
    Posts
    26
    Rep Power
    7

    Smile Server connection failure during transaction


    Hi folks,

    Yesterday my mail server crashed trying to start up after a backup. My backup procedure consists in stopping the service, then copying all the data and finally starting again the service. This last step produced the following error trace:



    ERROR TRACE

    Code:
    2010-02-16 02:10:59,489 FATAL [main] [] system - Config initialization failed
    com.zimbra.common.service.ServiceException: system failure: getting database connection
    ExceptionId:main:1266282659488:0bee2e9469f64bc7
    Code:service.FAILURE
            at com.zimbra.common.service.ServiceException.FAILURE(ServiceException.java:253)
            at com.zimbra.cs.db.DbPool.getConnection(DbPool.java:231)
            at com.zimbra.cs.util.Config.init(Config.java:62)
            at com.zimbra.cs.util.Config.initConfig(Config.java:89)
            at com.zimbra.cs.util.Config.getString(Config.java:101)
            at com.zimbra.cs.db.Versions.checkDBVersion(Versions.java:77)
            at com.zimbra.cs.db.Versions.checkVersions(Versions.java:73)
            at com.zimbra.cs.util.Zimbra.startup(Zimbra.java:115)
            at com.zimbra.soap.SoapServlet.init(SoapServlet.java:114)
            at javax.servlet.GenericServlet.init(GenericServlet.java:241)
            at org.mortbay.jetty.servlet.ServletHolder.initServlet(ServletHolder.java:433)
            at org.mortbay.jetty.servlet.ServletHolder.doStart(ServletHolder.java:256)
            at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:40)
            at org.mortbay.jetty.servlet.ServletHandler.initialize(ServletHandler.java:612)
            at org.mortbay.jetty.servlet.Context.startContext(Context.java:139)
            at org.mortbay.jetty.webapp.WebAppContext.startContext(WebAppContext.java:1222)
            at org.mortbay.jetty.handler.ContextHandler.doStart(ContextHandler.java:501)
            at org.mortbay.jetty.webapp.WebAppContext.doStart(WebAppContext.java:449)
            at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:40)
            at org.mortbay.jetty.handler.HandlerCollection.doStart(HandlerCollection.java:147)
            at org.mortbay.jetty.handler.ContextHandlerCollection.doStart(ContextHandlerCollection.java:161)
            at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:40)
            at org.mortbay.jetty.handler.HandlerCollection.doStart(HandlerCollection.java:147)
            at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:40)
            at org.mortbay.jetty.handler.HandlerWrapper.doStart(HandlerWrapper.java:117)
            at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:40)
            at org.mortbay.jetty.handler.HandlerWrapper.doStart(HandlerWrapper.java:117)
            at org.mortbay.jetty.Server.doStart(Server.java:217)
            at org.mortbay.setuid.SetUIDServer.doStart(SetUIDServer.java:100)
            at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:40)
            at org.mortbay.xml.XmlConfiguration.main(XmlConfiguration.java:979)
            at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
            at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
            at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
            at java.lang.reflect.Method.invoke(Method.java:597)
            at org.mortbay.start.Main.invokeMain(Main.java:183)
            at org.mortbay.start.Main.start(Main.java:497)
            at org.mortbay.start.Main.main(Main.java:115)
    Caused by: com.mysql.jdbc.exceptions.MySQLNonTransientConnectionException: Server connection failure during transaction. Due to underlying exception: 'java.net.SocketException: java.net.ConnectException: Connection refused'.
    
    ** BEGIN NESTED EXCEPTION **
    
    java.net.SocketException
    MESSAGE: java.net.ConnectException: Connection refused
    
    STACKTRACE:
    
    java.net.SocketException: java.net.ConnectException: Connection refused
            at com.mysql.jdbc.StandardSocketFactory.connect(StandardSocketFactory.java:156)
            at com.mysql.jdbc.MysqlIO.<init>(MysqlIO.java:276)
            at com.mysql.jdbc.Connection.createNewIO(Connection.java:2769)
            at com.mysql.jdbc.Connection.<init>(Connection.java:1531)
            at com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:266)
            at java.sql.DriverManager.getConnection(DriverManager.java:582)
            at java.sql.DriverManager.getConnection(DriverManager.java:154)
            at org.apache.commons.dbcp.DriverManagerConnectionFactory.createConnection(DriverManagerConnectionFactory.java:97)
            at org.apache.commons.dbcp.PoolableConnectionFactory.makeObject(PoolableConnectionFactory.java:300)
            at org.apache.commons.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:816)
            at org.apache.commons.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:140)
            at com.zimbra.cs.db.DbPool.getConnection(DbPool.java:222)
            at com.zimbra.cs.util.Config.init(Config.java:62)
            at com.zimbra.cs.util.Config.initConfig(Config.java:89)
            at com.zimbra.cs.util.Config.getString(Config.java:101)
            at com.zimbra.cs.db.Versions.checkDBVersion(Versions.java:77)
            at com.zimbra.cs.db.Versions.checkVersions(Versions.java:73)
            at com.zimbra.cs.util.Zimbra.startup(Zimbra.java:115)
            at com.zimbra.soap.SoapServlet.init(SoapServlet.java:114)
            at javax.servlet.GenericServlet.init(GenericServlet.java:241)
            at org.mortbay.jetty.servlet.ServletHolder.initServlet(ServletHolder.java:433)
            at org.mortbay.jetty.servlet.ServletHolder.doStart(ServletHolder.java:256)
            at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:40)
            at org.mortbay.jetty.servlet.ServletHandler.initialize(ServletHandler.java:612)
            at org.mortbay.jetty.servlet.Context.startContext(Context.java:139)
            at org.mortbay.jetty.webapp.WebAppContext.startContext(WebAppContext.java:1222)
            at org.mortbay.jetty.handler.ContextHandler.doStart(ContextHandler.java:501)
            at org.mortbay.jetty.webapp.WebAppContext.doStart(WebAppContext.java:449)
            at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:40)
            at org.mortbay.jetty.handler.HandlerCollection.doStart(HandlerCollection.java:147)
            at org.mortbay.jetty.handler.ContextHandlerCollection.doStart(ContextHandlerCollection.java:161)
            at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:40)
            at org.mortbay.jetty.handler.HandlerCollection.doStart(HandlerCollection.java:147)
            at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:40)
            at org.mortbay.jetty.handler.HandlerWrapper.doStart(HandlerWrapper.java:117)
            at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:40)
            at org.mortbay.jetty.handler.HandlerWrapper.doStart(HandlerWrapper.java:117)
            at org.mortbay.jetty.Server.doStart(Server.java:217)
            at org.mortbay.setuid.SetUIDServer.doStart(SetUIDServer.java:100)
            at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:40)
            at org.mortbay.xml.XmlConfiguration.main(XmlConfiguration.java:979)
            at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
            at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
            at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
            at java.lang.reflect.Method.invoke(Method.java:597)
            at org.mortbay.start.Main.invokeMain(Main.java:183)
            at org.mortbay.start.Main.start(Main.java:497)
            at org.mortbay.start.Main.main(Main.java:115)
    
    
    ** END NESTED EXCEPTION **
    
    
    
    Attempted reconnect 3 times. Giving up.
            at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:888)
            at com.mysql.jdbc.Connection.createNewIO(Connection.java:2838)
            at com.mysql.jdbc.Connection.<init>(Connection.java:1531)
            at com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:266)
            at java.sql.DriverManager.getConnection(DriverManager.java:582)
            at java.sql.DriverManager.getConnection(DriverManager.java:154)
            at org.apache.commons.dbcp.DriverManagerConnectionFactory.createConnection(DriverManagerConnectionFactory.java:97)
            at org.apache.commons.dbcp.PoolableConnectionFactory.makeObject(PoolableConnectionFactory.java:300)
            at org.apache.commons.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:816)
            at org.apache.commons.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:140)
            at com.zimbra.cs.db.DbPool.getConnection(DbPool.java:222)
            ... 36 more

    After this problem, I was able to start up the zimbra server manually with the zmcontrol command. I would appreciate some advice in order to prevent this error to happen.

    I have already read this thread. Now i follow this guides for increase the performance of our zimbra server too:


    - Mysql
    - LDAP


    Thanks a lot
    Last edited by samesisa; 02-16-2010 at 03:45 AM.

  2. #2
    Join Date
    Jun 2008
    Posts
    594
    Rep Power
    8

    Default

    This seems to be a problem with clean shutdown of mysql. Do you see any errors in /opt/zimbra/log/mysql.err file ?

  3. #3
    Join Date
    Jul 2008
    Posts
    26
    Rep Power
    7

    Default

    Thanks for reply!

    I couldn't get this file but I found some files that they are very similars, with this content:

    /opt/zimbra/db/data/hostname.err
    Code:
    100216  1:00:16  InnoDB: Starting shutdown...
    100216  1:00:18  InnoDB: Shutdown completed; log sequence number 1 463700086
    100216  1:00:18 [Note] /opt/zimbra/mysql/libexec/mysqld: Shutdown complete
    
    100216 01:00:18  mysqld ended
    
    100216 02:10:25  mysqld started
    Inconsistency detected by ld.so: dl-open.c: 610: _dl_open: Assertion `_dl_debug_initialize (0, args.nsid)->r_state == RT_CONSISTENT' failed!
    100216 02:10:25  mysqld ended
    
    100216 09:48:16  mysqld started
    100216  9:48:18  InnoDB: Started; log sequence number 1 463700086
    100216  9:48:18 [Note] /opt/zimbra/mysql/libexec/mysqld: ready for connections.
    Version: '5.0.51a-log'  socket: '/opt/zimbra/db/mysql.sock'  port: 7306  Source distribution


    /opt/zimbra/logger/db/data/hostname.err

    Code:
    100216  1:00:22  InnoDB: Starting shutdown...
    100216  1:00:23  InnoDB: Shutdown completed; log sequence number 0 43655
    100216  1:00:23 [Note] /opt/zimbra/logger/mysql/libexec/mysqld: Shutdown complete
    
    100216 01:00:23  mysqld ended
    
    100216 02:10:24  mysqld started
    100216  2:10:25  InnoDB: Started; log sequence number 0 43655
    100216  2:10:25 [Note] /opt/zimbra/logger/mysql/libexec/mysqld: ready for connections.
    Version: '5.0.51a-log'  socket: '/opt/zimbra/logger/db/mysql.sock'  port: 7307  Source distribution
    100216  9:45:38 [Note] /opt/zimbra/logger/mysql/libexec/mysqld: Normal shutdown
    
    100216  9:45:40  InnoDB: Starting shutdown...
    100216  9:45:42  InnoDB: Shutdown completed; log sequence number 0 43655
    100216  9:45:42 [Note] /opt/zimbra/logger/mysql/libexec/mysqld: Shutdown complete
    
    100216 09:45:42  mysqld ended
    
    100216 09:48:15  mysqld started
    100216  9:48:15  InnoDB: Started; log sequence number 0 43655
    100216  9:48:15 [Note] /opt/zimbra/logger/mysql/libexec/mysqld: ready for connections.
    Version: '5.0.51a-log'  socket: '/opt/zimbra/logger/db/mysql.sock'  port: 7307  Source distribution
    I didn't detect any error in mailbox.log on 16th of February, the day that i got problems with backup procedure.

    For this files i can see this on /opt/zimbra/db/data/hostname.err

    Inconsistency detected by ld.so: dl-open.c: 610: _dl_open: Assertion `_dl_debug_initialize (0, args.nsid)->r_state == RT_CONSISTENT' failed!
    I found information abaout this Inconsistency without success. Maybe I need upgrade some library Is it a specific issue??

    Some advice?

    Thanks!




    * We didn't get more errors these days, since 16-Freb-2010, on startup before backup procedure. I edited some configurations following this guide:
    Quote Originally Posted by samesisa View Post
    Last edited by samesisa; 02-18-2010 at 01:25 AM.

  4. #4
    Join Date
    Jul 2008
    Posts
    26
    Rep Power
    7

    Default

    Today we had new crash on zimbra server after backup procedure. I didn't found the same error on

    /opt/zimbra/db/data/hostname.err
    Code:
    100219  1:00:16  InnoDB: Starting shutdown...
    100219  1:00:20  InnoDB: Shutdown completed; log sequence number 1 488376754
    100219  1:00:20 [Note] /opt/zimbra/mysql/libexec/mysqld: Shutdown complete
    
    100219 01:00:20  mysqld ended
    
    100219 02:10:35  mysqld started
    100219  2:10:40  InnoDB: Started; log sequence number 1 488376754
    100219  2:10:40 [Note] /opt/zimbra/mysql/libexec/mysqld: ready for connections.
    Version: '5.0.51a-log'  socket: '/opt/zimbra/db/mysql.sock'  port: 7306  Source distribution

    But i see this on /opt/zimbra/log/zmmailboxd.out

    Code:
    2010-02-18 01:00:09
    Full thread dump Java HotSpot(TM) 64-Bit Server VM (10.0-b19 mixed mode):
    
    "Pop3Server-3884" prio=10 tid=0x00002aabdad99000 nid=0x6e76 runnable [0x0000000042c7c000..0x0000000042c7ce20]
       java.lang.Thread.State: RUNNABLE
            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.read(BufferedInputStream.java:237)
            - locked <0x00002aab9dd18b60> (a com.zimbra.cs.tcpserver.TcpServerInputStream)
            at com.zimbra.cs.tcpserver.TcpServerInputStream.readLine(TcpServerInputStream.java:73)
            at com.zimbra.cs.pop3.TcpPop3Handler.processCommand(TcpPop3Handler.java:48)
            at com.zimbra.cs.tcpserver.ProtocolHandler.processConnection(ProtocolHandler.java:160)
            at com.zimbra.cs.tcpserver.ProtocolHandler.run(ProtocolHandler.java:128)
            at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
            at java.lang.Thread.run(Thread.java:619)
    
    "btpool0-462" prio=10 tid=0x00002aabd7be5400 nid=0x6e6e in Object.wait() [0x0000000043190000..0x0000000043190aa0]
       java.lang.Thread.State: TIMED_WAITING (on object monitor)
            at java.lang.Object.wait(Native Method)
            - waiting on <0x00002aab9db9b640> (a org.mortbay.thread.BoundedThreadPool$PoolThread)
            at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:482)
            - locked <0x00002aab9db9b640> (a org.mortbay.thread.BoundedThreadPool$PoolThread)
    
    "ImapServer-5312" prio=10 tid=0x00002aabd834ec00 nid=0x455d runnable [0x0000000041d81000..0x0000000041d81ba0]
       java.lang.Thread.State: RUNNABLE
            at java.net.SocketInputStream.socketRead0(Native Method)
            at java.net.SocketInputStream.read(SocketInputStream.java:129)
            at com.sun.net.ssl.internal.ssl.InputRecord.readFully(InputRecord.java:293)
            at com.sun.net.ssl.internal.ssl.InputRecord.read(InputRecord.java:331)
            at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:789)
            - locked <0x00002aab86f99c28> (a java.lang.Object)
            at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:746)
            at com.sun.net.ssl.internal.ssl.AppInputStream.read(AppInputStream.java:75)
            - locked <0x00002aab86f99cf0> (a com.sun.net.ssl.internal.ssl.AppInputStream)
            at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
            at java.io.BufferedInputStream.read(BufferedInputStream.java:237)
            - locked <0x00002aab86fc1490> (a com.zimbra.cs.tcpserver.TcpServerInputStream)
            at com.zimbra.cs.tcpserver.TcpServerInputStream.readLine(TcpServerInputStream.java:73)
            at com.zimbra.cs.imap.TcpImapRequest.continuation(TcpImapRequest.java:54)
            at com.zimbra.cs.imap.TcpImapHandler.processCommand(TcpImapHandler.java:107)
            at com.zimbra.cs.tcpserver.ProtocolHandler.processConnection(ProtocolHandler.java:160)
            at com.zimbra.cs.tcpserver.ProtocolHandler.run(ProtocolHandler.java:128)
            at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
            at java.lang.Thread.run(Thread.java:619)
    
    ........................
    
    "Reference Handler" daemon prio=10 tid=0x00002aabd75e7400 nid=0x2dfb in Object.wait() [0x0000000040089000..0x0000000040089da0]
       java.lang.Thread.State: WAITING (on object monitor)
            at java.lang.Object.wait(Native Method)
            - waiting on <0x00002aaab65400e0> (a java.lang.ref.Reference$Lock)
            at java.lang.Object.wait(Object.java:485)
            at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
            - locked <0x00002aaab65400e0> (a java.lang.ref.Reference$Lock)
    
    "VM Thread" prio=10 tid=0x00002aabd75e5000 nid=0x2dfa runnable
    
    "GC task thread#0 (ParallelGC)" prio=10 tid=0x000000004011d400 nid=0x2df6 runnable
    
    "GC task thread#1 (ParallelGC)" prio=10 tid=0x000000004011e800 nid=0x2df7 runnable
    
    "GC task thread#2 (ParallelGC)" prio=10 tid=0x000000004011fc00 nid=0x2df8 runnable
    
    "GC task thread#3 (ParallelGC)" prio=10 tid=0x0000000040121000 nid=0x2df9 runnable
    
    "VM Periodic Task Thread" prio=10 tid=0x00002aabd77cc000 nid=0x2e0d waiting on condition
    
    JNI global references: 1217
    
    Heap
     PSYoungGen      total 1336000K, used 691191K [0x00002aab76540000, 0x00002aabcd590000, 0x00002aabd6540000)
      eden space 1292544K, 50% used [0x00002aab76540000,0x00002aab9ddd7658,0x00002aabc5380000)
      from space 43456K, 99% used [0x00002aabc5380000,0x00002aabc7de66c8,0x00002aabc7df0000)
      to   space 69312K, 0% used [0x00002aabc91e0000,0x00002aabc91e0000,0x00002aabcd590000)
     PSOldGen        total 2851520K, used 700923K [0x00002aaab6540000, 0x00002aab645f0000, 0x00002aab76540000)
      object space 2851520K, 24% used [0x00002aaab6540000,0x00002aaae11becf0,0x00002aab645f0000)
     PSPermGen       total 49856K, used 49765K [0x00002aaaae540000, 0x00002aaab15f0000, 0x00002aaab6540000)
      object space 49856K, 99% used [0x00002aaaae540000,0x00002aaab15d95a8,0x00002aaab15f0000)

    What does it mean??Some advice?

    Thanks!

  5. #5
    Join Date
    Jun 2008
    Posts
    594
    Rep Power
    8

    Default

    So does it have a heap dump generated ?

Similar Threads

  1. zmmailboxdctl is not running !!!!!!
    By olibite in forum Administrators
    Replies: 14
    Last Post: 04-28-2011, 06:50 AM
  2. Replies: 3
    Last Post: 12-20-2010, 11:49 AM
  3. Connection error with Zimbra server.
    By Wilson_Lee in forum Users
    Replies: 9
    Last Post: 12-22-2009, 07:56 PM
  4. Error loading on Mac OS X 10.4.10 server PPC
    By qprcanada in forum Installation
    Replies: 7
    Last Post: 10-26-2007, 07:25 AM
  5. Is it started or not
    By kwelipatton in forum Installation
    Replies: 10
    Last Post: 03-28-2006, 11:11 PM

Posting Permissions

  • You may not post new threads
  • You may not post replies
  • You may not post attachments
  • You may not edit your posts
  •