Understanding what went wrong - I have what looks like a normal LR runtime

[Rob Silver, módosítva 10 év-val korábban]

I am trying to learn what happened to my test LR environment and would appreciate some insight.
I have a CENTOS/Tomcat bundle based environment - All seemed fine until suddenly it was not. The following was a healthy Liferay/ga2.log or version 6.1.1 version log
And I follow it with the bad log from the next day. Other than adding a URL in the site settings and proxypass entries no changes were made that is other than:
rm -r -f work/Catalina
rm -r -f temp
to clear the cache and re-initialize. This is something I would like to better understand in itself - Why do we do this to magically fix liferay?

Anyway the healthy Liferay log:
22:45:24,962 INFO [pool-2-thread-1][DialectDetector:71] Determine dialect for HSQL Database Engine 2
21:45:24,967 WARN [pool-2-thread-1][DialectDetector:86] Liferay is configured to use Hypersonic as its database. Do NOT use Hypersonic in production. Hypersonic is an embedded database useful for development and demo'ing purposes. The database settings can be changed in portal-ext.properties.
21:45:25,037 INFO [pool-2-thread-1][DialectDetector:136] Found dialect org.hibernate.dialect.HSQLDialect
21:46:57,228 INFO [pool-2-thread-1][BaseDB:452] Database supports case sensitive queries
21:46:59,997 INFO [pool-2-thread-1][VerifyProcess:81] Verifying com.liferay.portal.verify.VerifyProcessSuite
21:46:59,999 INFO [pool-2-thread-1][VerifyProcess:81] Verifying com.liferay.portal.verify.VerifyProperties
21:47:01,417 INFO [pool-2-thread-1][VerifyProcess:81] Verifying com.liferay.portal.verify.VerifyDB2
21:47:01,423 INFO [pool-2-thread-1][VerifyProcess:81] Verifying com.liferay.portal.verify.VerifyMySQL
21:47:01,424 INFO [pool-2-thread-1][VerifyProcess:81] Verifying com.liferay.portal.verify.VerifyOracle
21:47:01,426 INFO [pool-2-thread-1][VerifyProcess:81] Verifying com.liferay.portal.verify.VerifySQLServer
21:47:01,426 INFO [pool-2-thread-1][VerifyProcess:81] Verifying com.liferay.portal.verify.VerifyCounter
21:47:01,533 INFO [pool-2-thread-1][VerifyProcess:81] Verifying com.liferay.portal.verify.VerifyUUID
21:47:01,600 INFO [pool-2-thread-1][VerifyProcess:81] Verifying com.liferay.portal.verify.VerifyPermission
21:47:10,095 INFO [pool-2-thread-1][VerifyProcess:81] Verifying com.liferay.portal.verify.VerifyRole
21:47:10,578 INFO [pool-2-thread-1][VerifyProcess:81] Verifying com.liferay.portal.verify.VerifyAsset
21:47:10,626 INFO [pool-2-thread-1][UpgradeProcess:207] Upgrading com.liferay.portal.upgrade.util.UpgradeAssetPublisherManualEntries
21:47:10,642 INFO [pool-2-thread-1][VerifyProcess:81] Verifying com.liferay.portal.verify.VerifyBlogs
21:47:10,714 INFO [pool-2-thread-1][VerifyProcess:81] Verifying com.liferay.portal.verify.VerifyBookmarks
21:47:10,769 INFO [pool-2-thread-1][VerifyProcess:81] Verifying com.liferay.portal.verify.VerifyCalendar
21:47:10,916 INFO [pool-2-thread-1][VerifyProcess:81] Verifying com.liferay.portal.verify.VerifyDocumentLibrary
21:47:11,225 INFO [pool-2-thread-1][VerifyProcess:81] Verifying com.liferay.portal.verify.VerifyGroup
21:47:12,409 INFO [pool-2-thread-1][VerifyProcess:81] Verifying com.liferay.portal.verify.VerifyJournal
21:47:12,966 INFO [pool-2-thread-1][VerifyProcess:81] Verifying com.liferay.portal.verify.VerifyLayout
21:47:13,025 INFO [pool-2-thread-1][VerifyProcess:81] Verifying com.liferay.portal.verify.VerifyMessageBoards
21:47:13,354 INFO [pool-2-thread-1][VerifyProcess:81] Verifying com.liferay.portal.verify.VerifyOrganization
21:47:13,548 INFO [pool-2-thread-1][VerifyProcess:81] Verifying com.liferay.portal.verify.VerifyResourcePermissions
21:47:15,510 INFO [pool-2-thread-1][VerifyResourcePermissions:147] Processed 100 resource permissions for com.liferay.portal.model.User
21:47:16,222 INFO [pool-2-thread-1][VerifyProcess:81] Verifying com.liferay.portal.verify.VerifySocial
21:47:16,223 INFO [pool-2-thread-1][VerifyProcess:81] Verifying com.liferay.portal.verify.VerifyUser
21:47:16,249 INFO [pool-2-thread-1][VerifyProcess:81] Verifying com.liferay.portal.verify.VerifyWiki
21:47:16,525 INFO [pool-2-thread-1][ServerDetector:154] Server supports hot deploy
21:47:39,106 INFO [pool-2-thread-1][PluginPackageUtil:1030] Reading plugin package for the root context
21:49:23,958 INFO [pool-2-thread-1][AutoDeployDir:85] Creating missing directory /root/liferay-portal-6.1.1-ce-ga2/deploy
21:49:24,073 INFO [pool-2-thread-1][AutoDeployDir:106] Auto deploy scanner started for /root/liferay-portal-6.1.1-ce-ga2/deploy
22:23:17,709 INFO [http-bio-8080-exec-3][HotDeployImpl:178] Deploying marketplace-portlet from queue
22:23:21,132 INFO [http-bio-8080-exec-3][PluginPackageUtil:1033] Reading plugin package for marketplace-portlet
22:23:40,593 INFO [http-bio-8080-exec-3][ServiceComponentLocalServiceImpl:271] Running Marketplace SQL scripts
22:24:41,850 INFO [http-bio-8080-exec-3][HookHotDeployListener:550] Registering hook for marketplace-portlet
22:24:48,150 INFO [http-bio-8080-exec-3][HookHotDeployListener:690] Hook for marketplace-portlet is available for use
22:25:37,221 INFO [http-bio-8080-exec-3][HotDeployImpl:178] Deploying resources-importer-web from queue
22:25:37,387 INFO [http-bio-8080-exec-3][PluginPackageUtil:1033] Reading plugin package for resources-importer-web
22:25:55,523 INFO [http-bio-8080-exec-3][HotDeployEvent:109] Plugin welcome-theme requires resources-importer-web
22:26:01,453 INFO [http-bio-8080-exec-3][HotDeployImpl:178] Deploying welcome-theme from queue
22:26:01,454 INFO [http-bio-8080-exec-3][PluginPackageUtil:1033] Reading plugin package for welcome-theme
22:26:14,597 INFO [http-bio-8080-exec-3][ThemeHotDeployListener:87] Registering themes for welcome-theme
22:26:30,940 INFO [http-bio-8080-exec-3][ThemeHotDeployListener:100] 1 theme for welcome-theme is available for use
22:26:39,838 INFO [liferay/hot_deploy-1][HotDeployMessageListener:151] Importing resources from welcome-theme to group 19
22:37:24,553 INFO [com.liferay.portal.plugin.PluginPackageUtil][PluginPackageUtil:1421] Checking for available updates
22:37:55,175 INFO [com.liferay.portal.plugin.PluginPackageUtil][PluginPackageUtil:1465] Finished checking for available updates in 29985 ms

Now here is what happened - There were problems shutting down the tomcat server followed the now defunct log::

15:47:36,706 WARN [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2][BasicResourcePool:1841] com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@585125d2 -- Acquisition Attempt Failed!!! Clearing pending acquires. While trying to acquire a needed new resource, we failed to succeed more than the maximum number of allowed acquisition attempts (3). Last acquisition attempt exception:
com.mysql.jdbc.CommunicationsException: Communications link failure due to underlying exception:

** BEGIN NESTED EXCEPTION **

java.net.ConnectException
MESSAGE: Connection refused

STACKTRACE:

java.net.ConnectException: Connection refused
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391)
at java.net.Socket.connect(Socket.java:579)
at java.net.Socket.connect(Socket.java:528)
at java.net.Socket.<init>(Socket.java:425)
at java.net.Socket.<init>(Socket.java:241)
at com.mysql.jdbc.StandardSocketFactory.connect(StandardSocketFactory.java:256)
at com.mysql.jdbc.MysqlIO.<init>(MysqlIO.java:271)
at com.mysql.jdbc.Connection.createNewIO(Connection.java:2744)
at com.mysql.jdbc.Connection.<init>(Connection.java:1553)
at com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:285)
at com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:134)
at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:182)
at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:148)
at com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:1014)
at com.mchange.v2.resourcepool.BasicResourcePool.access$800(BasicResourcePool.java:32)
at com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1810)
at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)

** END NESTED EXCEPTION **

Last packet sent to the server was 1 ms ago.
at com.mysql.jdbc.Connection.createNewIO(Connection.java:2820)
at com.mysql.jdbc.Connection.<init>(Connection.java:1553)
at com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:285)
at com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:134)
at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:182)
at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:148)
at com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:1014)
at com.mchange.v2.resourcepool.BasicResourcePool.access$800(BasicResourcePool.java:32)
at com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1810)
at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)
15:47:36,737 WARN [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#3][BasicResourcePool:1841] com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@25ad95f8 -- Acquisition Attempt Failed!!! Clearing pending acquires. While trying to acquire a needed new resource, we failed to succeed more than the maximum number of allowed acquisition attempts (3). Last acquisition attempt exception:

........
Now as I understand it it ceased to connect to the mysqld actually MariaDB database in this case and if I fix this all should be well or is there a database integrity issue in play here and how do I determine if its not even making the connection or database integrity piece from this log output. Could it just be a semiphore file was simply not cleared?
what file might I be looking for?



Now

[Rob Silver, módosítva 10 év-val korábban]

I have seen some similar postings surprisingly as I delve into the issues of ThreadPools and Liferay I become aware of the possible alternatives:
DBCP, and Primrose although thus far I do not see which of these is most advantageous. Perhaps someone can help me figure out where(which file exactly) would I place presumably:
jdbc.default.liferay.pool.provider=DBCP or
jdbc.default.liferay.pool.provider=Primrose
I understand c3p0 is the default ThreadPool for Liferay ex

[David H Nebinger, módosítva 10 év-val korábban]

Rob Silver:

22:45:24,962 INFO [pool-2-thread-1][DialectDetector:71] Determine dialect for HSQL Database Engine 2
........
Now as I understand it it ceased to connect to the mysqld actually MariaDB database in this case

Um, it's not connecting to mysql/maria at all, it's connecting to HSQLDB...

[Rob Silver, módosítva 10 év-val korábban]

Yes its just wierd. One does not expect a server to just stop working without understanding what went wrong.
This must be better understood. I am planning to stick my neck on the line for Liferay using the CE server at first and perhaps the EE server eventually but this is a huge problem on my current server. I may rebuild the server and even get everything working but unless I understand what went wrong and how to fix it I am sunk.

How would you suggest I best approach this probem? Should I go through the SVN source code for Liferay that version is 6.1.2 or
liferay-portal-6.1.2-ce-ga3 and I am currently struggling with this problem on liferay-portal-6.1.1-ce-ga2].

Also even if I were to do that I may still have to better understand the thread pools based on my current error or it could happen again.
So lets look at the logged warning:
Note my wizards property file looks as follows minus the security stuff like userid/passwd:
liferay.home=/root/liferay-portal-6.1.1-ce-ga2
admin.email.from.address=[e-mail]
jdbc.default.driverClassName=com.mysql.jdbc.Driver
jdbc.default.username=mysqluser
jdbc.default.url=jdbc:mysql://localhost:3306/lportal?useUnicode=true&characterEncoding=UTF-8&useFastDateParsing=false
setup.wizard.enabled=false

Now this keeps repeating but there are many aspects I do not understand:

1st there is the warning Acquisition attempt failed??? Are we talking acquisition of a connection to the database? If so why? How might I debug this?
Clearing pending acquires?? Again what is really happening here?
How might I obtain more detail with this error. Perhaps using wireshark to track the network traffic especially considering all is localhost sockets? Seems overkill

01:35:45,725 WARN [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0][BasicResourcePool:1841] com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@7a751499 -- Acquisition Attempt Failed!!! Clearing pending acquires. While trying to acquire a needed new resource, we failed to succeed more than the maximum number of allowed acquisition attempts (3). Last acquisition attempt exception:
com.mysql.jdbc.CommunicationsException: Communications link failure due to underlying exception:

** BEGIN NESTED EXCEPTION **

java.net.ConnectException
MESSAGE: Connection refused

STACKTRACE:

java.net.ConnectException: Connection refused
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391)
at java.net.Socket.connect(Socket.java:579)
at java.net.Socket.connect(Socket.java:528)
at java.net.Socket.<init>(Socket.java:425)
at java.net.Socket.<init>(Socket.java:241)
at com.mysql.jdbc.StandardSocketFactory.connect(StandardSocketFactory.java:256)
at com.mysql.jdbc.MysqlIO.<init>(MysqlIO.java:271)
at com.mysql.jdbc.Connection.createNewIO(Connection.java:2744)
at com.mysql.jdbc.Connection.<init>(Connection.java:1553)
at com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:285)
at com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:134)
at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:182)
at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:148)
at com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:1014)
at com.mchange.v2.resourcepool.BasicResourcePool.access$800(BasicResourcePool.java:32)
at com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1810)
at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)


** END NESTED EXCEPTION **



Last packet sent to the server was 0 ms ago.
at com.mysql.jdbc.Connection.createNewIO(Connection.java:2820)
at com.mysql.jdbc.Connection.<init>(Connection.java:1553)
at com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:285)
at com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:134)
at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:182)
at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:148)
at com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:1014)
at com.mchange.v2.resourcepool.BasicResourcePool.access$800(BasicResourcePool.java:32)
at com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1810)
at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)

[Rob Silver, módosítva 10 év-val korábban]

After much consideration I have concluded that I accidently overwrote the MariaDB database libraries when I accidently started the dormant unconfigured MySQLD server
which uses the same default folders or directories.

So I decided to for now abandon MariaDB and instead am using MySQL Server version 5.5.33 and now after just restoring the database I am back to where I was before it stopped working - Hurray!!!. Sadly I was unable to get MariaDB working hopefully Version 5.5.33 has enough bells and whistles to make things work effectively as a replacement.

I have come to the conclusion when configuration files and drivers get mangled in such a way its time to re-install the database and import the last good export of data to correct the problem.