Zimbra offers Open Source email server software and shared calendar for Linux and the Mac
Go Back   Zimbra :: Forums > Zimbra Collaboration Suite > Administrators
Reload this Page Server connection failure during transaction

Welcome to the Zimbra :: Forums!
Welcome, if you would like to post a comment please register. We also encourage you to explore all things Zimbra with our team and members of the community.

Reply
 
LinkBack Thread Tools Search this Thread Display Modes
  #1 (permalink)  
Old 02-16-2010, 02:04 AM
Active Member
  
Posts: 26
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 02:45 AM..
Reply With Quote
  #2 (permalink)  
Old 02-17-2010, 10:45 AM
Outstanding Member
  
Posts: 594
Default
This seems to be a problem with clean shutdown of mysql. Do you see any errors in /opt/zimbra/log/mysql.err file ?
Reply With Quote
  #3 (permalink)  
Old 02-18-2010, 12:13 AM
Active Member
  
Posts: 26
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

Quote:
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 12:25 AM..
Reply With Quote
  #4 (permalink)  
Old 02-19-2010, 04:51 AM
Active Member
  
Posts: 26
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!
Reply With Quote
  #5 (permalink)  
Old 02-19-2010, 06:22 AM
Outstanding Member
  
Posts: 594
Default
So does it have a heap dump generated ?
Reply With Quote
Reply

« Previous Thread | Today's Posts or Week's Posts | Next Thread »

Thread Tools Search this Thread
Search this Thread:

Advanced Search
Display Modes
Linear Mode Linear Mode


Similar Threads

Product Information

Why Join?

Registering let's you ask questions, makes it easier to search, displays any files attached to posts, and notifies you about replies.

blog.zimbra.com


Home - Blog - Contact Us - Archive - Top


 

SEO by vBSEO ©2011, Crawlability, Inc.