I found the following differences in the catalina.out file with bin log enabled and disabled. Can you point me in the right direction on debugging the actual /client application further. Obviously the problem is
Jun 10, 2014 2:12:48 PM org.apache.catalina.core.StandardContext start SEVERE: Error listenerStart I could use a point in the right direction to get further debugging info. WITH BINLOG INFO [c.c.u.c.ComponentContext] (main:null) Setup Spring Application context INFO [c.c.s.GsonHelper] (main:null) Default Builder inited. Jun 10, 2014 2:12:48 PM org.apache.catalina.core.StandardContext start SEVERE: Error listenerStart Jun 10, 2014 2:12:48 PM org.apache.catalina.core.StandardContext start SEVERE: Context [/client] startup failed due to previous errors Jun 10, 2014 2:12:48 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads SEVERE: A web application appears to have started a thread named [FileWatchdog] but has failed to stop it. This is very likely to create a memory leak. Jun 10, 2014 2:12:48 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads SEVERE: A web application appears to have started a thread named [Timer-0] but has failed to stop it. This is very likely to create a memory leak. Jun 10, 2014 2:12:48 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads SEVERE: A web application appears to have started a thread named [ConnectionConcierge-1] but has failed to stop it. This is very likely to create a memory leak. Jun 10, 2014 2:12:48 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads SEVERE: A web application appears to have started a thread named [ClusteredAgentManager Timer] but has failed to stop it. This is very likely to create a memory leak. Jun 10, 2014 2:12:48 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads SEVERE: A web application appears to have started a thread named [Timer-1] but has failed to stop it. This is very likely to create a memory leak. Jun 10, 2014 2:12:48 PM org.apache.catalina.loader.WebappClassLoader clearThreadLocalMap SEVERE: A web application created a ThreadLocal with key of type [org.springframework.core.NamedThreadLocal] (value [Prototype beans currently in creation]) and a value of type [null] (value [null]) but failed to remove it when the web application was stopped. To prevent a memory leak, the ThreadLocal has be en forcibly removed. WITHOUT BINLOG INFO [c.c.u.c.ComponentContext] (main:null) Setup Spring Application context INFO [c.c.s.GsonHelper] (main:null) Default Builder inited. INFO [o.a.c.s.l.CloudStackExtendedLifeCycle] (main:null) Running system integrity checker com.cloud.upgrade.DatabaseIntegrityChecker@7f2af4a3 INFO [c.c.u.DatabaseIntegrityChecker] (main:null) Grabbing lock to check for database integrity. INFO [c.c.u.DatabaseIntegrityChecker] (main:null) Performing database integrity check INFO [o.a.c.s.l.CloudStackExtendedLifeCycle] (main:null) Running system integrity checker org.apache.cloudstack.utils.identity.ManagementServerNode@7c73b9ad INFO [o.a.c.s.l.CloudStackExtendedLifeCycle] (main:null) Configuring CloudStack Components INFO [c.c.u.d.GenericDaoBase] (main:null) Cache created: [ name = UserDaoImpl status = STATUS_ALIVE eternal = false overflowToDisk = false maxEntriesLocalHeap = 5000 maxEntriesLocalDisk = 0 memoryStoreEvictionPolicy = LRU timeToLiveSeconds = 300 timeToIdleSeconds = 300 persistence = none diskExpiryThreadInt ervalSeconds = 120 cacheEventListeners: net.sf.ehcache.statistics.LiveCacheStatisticsWrapper hitCount = 0 memoryStoreHitCount = 0 diskStoreHitCount = 0 missCountNotFound = 0 missCountExpired = 0 maxBytesLocalHeap = 0 overflowToOffHeap = false maxBytesLocalOffHeap = 0 maxBytesLocalDisk = 0 pinned = false ] INFO [c.c.u.d.GenericDaoBase] (main:null) Cache created: [ name = VMTemplateDaoImpl status = STATUS_ALIVE eternal = false overflowToDisk = false maxEntriesLocalHeap = 100 maxEntriesLocalDisk = 0 memoryStoreEvictionPolicy = LRU timeToLiveSeconds = 600 timeToIdleSeconds = 300 persistence = none diskExpiryThre adIntervalSeconds = 120 cacheEventListeners: net.sf.ehcache.statistics.LiveCacheStatisticsWrapper hitCount = 0 memoryStoreHitCount = 0 diskStoreHitCount = 0 missCountNotFound = 0 missCountExpired = 0 maxBytesLocalHeap = 0 overflowToOffHeap = false maxBytesLocalOffHeap = 0 maxBytesLocalDisk = 0 pinned = fals e ] INFO [c.c.u.d.GenericDaoBase] (main:null) Cache created: [ name = ServiceOfferingDaoImpl status = STATUS_ALIVE eternal = false overflowToDisk = false maxEntriesLocalHeap = 50 maxEntriesLocalDisk = 0 memoryStoreEvictionPolicy = LRU timeToLiveSeconds = 600 timeToIdleSeconds = 300 persistence = none diskExpiry ThreadIntervalSeconds = 120 cacheEventListeners: net.sf.ehcache.statistics.LiveCacheStatisticsWrapper hitCount = 0 memoryStoreHitCount = 0 diskStoreHitCount = 0 missCountNotFound = 0 missCountExpired = 0 maxBytesLocalHeap = 0 overflowToOffHeap = false maxBytesLocalOffHeap = 0 maxBytesLocalDisk = 0 pinned = false ] INFO [c.c.u.d.GenericDaoBase] (main:null) Cache created: [ name = DiskOfferingDaoImpl status = STATUS_ALIVE eternal = false overflowToDisk = false maxEntriesLocalHeap = 50 maxEntriesLocalDisk = 0 memoryStoreEvictionPolicy = LRU timeToLiveSeconds = 600 timeToIdleSeconds = 300 persistence = none diskExpiryThr eadIntervalSeconds = 120 cacheEventListeners: net.sf.ehcache.statistics.LiveCacheStatisticsWrapper hitCount = 0 memoryStoreHitCount = 0 diskStoreHitCount = 0 missCountNotFound = 0 missCountExpired = 0 maxBytesLocalHeap = 0 overflowToOffHeap = false maxBytesLocalOffHeap = 0 maxBytesLocalDisk = 0 pinned = fal se ] [cid:image001.jpg@01CF54D3.D25E1ED0] On Jun 10, 2014, at 10:30 AM, Rafael Weingartner <rafaelweingart...@gmail.com<mailto:rafaelweingart...@gmail.com>> wrote: you do not need to debug into the mysql, you just need to find the stack trace in the tomcat that is causing the app to shutdown during the start up process On Tue, Jun 10, 2014 at 11:26 AM, Steve Searles <ssear...@zimcom.net<mailto:ssear...@zimcom.net>> wrote: Yes, I will see if I can get any more debugging info out of it. Yes that is the URL we are using to access. In the condition where the bin log is on I get a 404 from tomcat meaning that the application has not started. I will try some further debugging on the mysql side as well. This is not an upgrade but rather a fresh install of 4.3. That is the problem I am seeing as well, no useful debug information. Steve Searles On Jun 10, 2014, at 8:21 AM, Rafael Weingartner < rafaelweingart...@gmail.com<mailto:rafaelweingart...@gmail.com>> wrote: I thought that it could be a missing dependency problem, because with CS 4.3 upgrade from 4.2.1 we had one. The mysql jdbc .jar was not in the classpath. So, we had to manually add it. I did not see any expressive tty in your log files. Could you look for some more meaningful java stack traces, then we might be able to help you. BTW, how are you trying to access the CS? http://serverIp:8080/client ? On Mon, Jun 9, 2014 at 11:31 PM, Steve Searles <ssear...@zimcom.net<mailto:ssear...@zimcom.net>> wrote: It is also worth noting that these are the last two DB queries that happen before the stop. So it may have something to do with cloudbridge? 140609 22:28:00 8 Connect cl...@db01.cvg.cs.zimcom.net<mailto:cl...@db01.cvg.cs.zimcom.net> on cloudbridge 8 Query /* mysql-connector-java-5.1.17-SNAPSHOT ( Revision: ${bzr.revision-id} ) */SHOW VARIABLES WHERE Variable_name ='language' OR Variable_name = 'net_write_timeout' OR Variable_name = 'interactive_timeout' OR Variable_name = 'wait_timeout' OR Variable_name = 'character_set_client' OR Variable_name = 'character_set_connection' OR Variable_name = 'character_set' OR Variable_name = 'character_set_server' OR Variable_name = 'tx_isolation' OR Variable_name = 'transaction_isolation' OR Variable_name = 'character_set_results' OR Variable_name = 'timezone' OR Variable_name = 'time_zone' OR Variable_name = 'system_time_zone' OR Variable_name = 'lower_case_table_names' OR Variable_name = 'max_allowed_packet' OR Variable_name = 'net_buffer_length' OR Variable_name = 'sql_mode' OR Variable_name = 'query_cache_type' OR Variable_name = 'query_cache_size' OR Variable_name = 'init_connect' 8 Query /* mysql-connector-java-5.1.17-SNAPSHOT ( Revision: ${bzr.revision-id} ) */SELECT @@session.auto_increment_increment 8 Query SHOW COLLATION 8 Query SET NAMES latin1 8 Query SET character_set_results = NULL 8 Query SET autocommit=1 8 Query SET sql_mode='STRICT_TRANS_TABLES' 8 Query SET autocommit=0 8 Query SET autocommit=0 8 Query SELECT offering_bundle.ID, offering_bundle.AmazonEC2Offering, offering_bundle.CloudStackOffering FROM offering_bundle 8 Query commit 8 Query rollback 8 Query SET autocommit=1 8 Query SET autocommit=0 8 Query SET autocommit=0 8 Query SELECT mhost.ID, mhost.MHostKey, mhost.Host, mhost.Version, mhost.LastHeartbeatTime FROM mhost WHERE mhost.MHostKey = _binary'00:50:56:92:04:18' ORDER BY RAND() LIMIT 1 8 Query commit 8 Query rollback 8 Query SET autocommit=1 8 Query SET autocommit=0 8 Query SET autocommit=0 8 Query UPDATE mhost SET mhost.Host=_binary' http://localhost:7080/awsapi' WHERE mhost.ID = 1 8 Query commit 8 Query rollback 8 Query SET autocommit=1 8 Query SET autocommit=0 8 Query SET autocommit=0 8 Query SELECT shost.ID, shost.Host, shost.HostType, shost.MHostID, shost.ExportRoot, shost.UserOnHost, shost.UserPassword FROM shost WHERE shost.MHostID = 1 AND shost.ExportRoot = _binary'/Users/john1/S3-Mount' ORDER BY RAND() LIMIT 1 8 Query commit 8 Query rollback 8 Query SET autocommit=1 9 Connect cl...@db01.cvg.cs.zimcom.net<mailto:cl...@db01.cvg.cs.zimcom.net> on cloud 9 Query /* mysql-connector-java-5.1.17-SNAPSHOT ( Revision: ${bzr.revision-id} ) */SHOW VARIABLES WHERE Variable_name ='language' OR Variable_name = 'net_write_timeout' OR Variable_name = 'interactive_timeout' OR Variable_name = 'wait_timeout' OR Variable_name = 'character_set_client' OR Variable_name = 'character_set_connection' OR Variable_name = 'character_set' OR Variable_name = 'character_set_server' OR Variable_name = 'tx_isolation' OR Variable_name = 'transaction_isolation' OR Variable_name = 'character_set_results' OR Variable_name = 'timezone' OR Variable_name = 'time_zone' OR Variable_name = 'system_time_zone' OR Variable_name = 'lower_case_table_names' OR Variable_name = 'max_allowed_packet' OR Variable_name = 'net_buffer_length' OR Variable_name = 'sql_mode' OR Variable_name = 'query_cache_type' OR Variable_name = 'query_cache_size' OR Variable_name = 'init_connect' 9 Query /* mysql-connector-java-5.1.17-SNAPSHOT ( Revision: ${bzr.revision-id} ) */SELECT @@session.auto_increment_increment 9 Query SHOW COLLATION 9 Query SET NAMES latin1 9 Query SET character_set_results = NULL 9 Query SET autocommit=1 9 Query SET sql_mode='STRICT_TRANS_TABLES' 9 Query SET autocommit=0 9 Query SELECT @@session.tx_isolation 9 Query SET SESSION TRANSACTION ISOLATION LEVEL READ COMMITTED 9 Query SELECT 1 9 Query SET autocommit=0 9 Query SELECT configuration.name, configuration.value FROM configuration WHERE configuration.name = _binary'enable.ec2.api' ORDER BY RAND() LIMIT 1 9 Query commit 9 Query rollback 9 Query SET autocommit=1 Steve Searles -----Original Message----- From: Steve Searles [mailto:ssear...@zimcom.net] Sent: Monday, June 9, 2014 10:19 PM To: users@cloudstack.apache.org<mailto:users@cloudstack.apache.org> Subject: RE: Management Server Startup Issue Rafael, Thank you for responding so quickly. Yes 4.3.0. I am using a dedicated DB servers and dedicated management servers. I will provide whatever log files you would find useful. It would be odd if it was a dependancy since CS really has no visibility to the sql server other than a connect string? Or so I thought; and the system is running fine with the binlog off. With the bin log on I can run queries from the command line and everything seems normal from the sql end, but the management server will not run. Toggle binlog off CS works fine. The replication slave has not even been started yet. Let me know what other info I can send over that would be of help. There is nothing in the catalina logs of interest and my logging level is currently set to trace for the management-server.log. I will turn on the sql query log and compare them between startups of the management nodes perhaps that will yeild something. I have included a dropbox link with the management server log from a normal startup of CS and one with mysql binlog enabled. Any help would be greatly appriciated. https://dl.dropboxusercontent.com/u/51895629/management-server.logs.tar.gz Steve Searles -----Original Message----- From: Rafael Weingartner [mailto:rafaelweingart...@gmail.com] Sent: Monday, June 9, 2014 6:57 PM To: users@cloudstack.apache.org Subject: Re: Management Server Startup Issue please give more logs. It is the 4.3.0 right? I bet there is a problem with a missing dependency. On Mon, Jun 9, 2014 at 7:32 PM, Steve Searles <ssear...@zimcom.net> wrote: Anyone have any idea why the management service would refuse to start if the DB server is configured as a master for replication? log_bin=mysql-bin server_id=1 Adding the above the my.cnf file of my DB server, restarting mysql then restarting cloudstack-managment will cause cloudstack to get hung on startup here. 2014-06-09 18:25:33,769 INFO [c.c.u.c.ComponentContext] (main:null) Starting com.cloud.bridge.persist.dao.SHostDaoImpl_EnhancerByCloudStack_9da5499 b 2014-06-09 18:25:33,769 INFO [c.c.u.c.ComponentContext] (main:null) Starting com.cloud.bridge.persist.dao.SObjectDaoImpl_EnhancerByCloudStack_847fb 98c 2014-06-09 18:25:33,769 INFO [c.c.u.c.ComponentContext] (main:null) Starting com.cloud.bridge.persist.dao.CloudStackUserDaoImpl_EnhancerByCloudStac k_7fce3ee6 2014-06-09 18:25:33,769 INFO [c.c.u.c.ComponentContext] (main:null) Starting com.cloud.bridge.service.core.ec2.EC2Engine_EnhancerByCloudStack_d70c9 e3c 2014-06-09 18:25:33,769 INFO [c.c.u.c.ComponentContext] (main:null) Starting com.cloud.bridge.service.controller.s3.ServiceProvider_EnhancerByCloud Stack_23d38b1 That is the last few lines of the management-server.log and it will hang there indefinitely. I noticed this on startup as well. 2014-06-09 18:25:16,841 INFO [c.c.u.d.T.Transaction] (main:null) Is Data Base High Availiability enabled? Ans : false 2014-06-09 18:25:17,164 DEBUG [c.c.u.d.ConnectionConcierge] (main:null) Registering a database connection for LockMaster1 2014-06-09 18:25:17,164 INFO [c.c.u.d.Merovingian2] (main:null) Cleaning up locks for 345049793560 2014-06-09 18:25:17,175 INFO [c.c.u.d.Merovingian2] (main:null) Released 0 locks for 345049793560 2014-06-09 18:25:17,206 INFO [o.a.c.s.l.CloudStackExtendedLifeCycle] (main:null) Running system integrity checker com.cloud.upgrade.DatabaseUpgradeChecker@63c8e4ae 2014-06-09 18:25:17,207 INFO [c.c.u.DatabaseUpgradeChecker] (main:null) Grabbing lock to check for database upgrade. 2014-06-09 18:25:17,254 DEBUG [c.c.u.d.VersionDaoImpl] (main:null) Checking to see if the database is at a version before it was the version table is created 2014-06-09 18:25:17,295 INFO [c.c.u.DatabaseUpgradeChecker] (main:null) DB version = 4.3.0 Code Version = 4.3.0 2014-06-09 18:25:17,296 INFO [c.c.u.DatabaseUpgradeChecker] (main:null) DB version and code version matches so no upgrade needed. The management server talking to the DB server at least enough to check the version; and mysql from the command line on the management server works fine as well. This line caught my attention. 2014-06-09 18:25:16,841 INFO [c.c.u.d.T.Transaction] (main:null) Is Data Base High Availiability enabled? Ans : false Is there something I need to set when using mysql replication specific to cloudstack? I do not see anything in the documentation on this other than setting up basic replication. if I comment out the above two lines in my.cnf and restart the management server it fires up just fine. I don’t get how enabling bin log would make a difference at all. Any help or explication for this strange issue would be appreciated. - Steve Searles -- Rafael Weingärtner -- Rafael Weingärtner -- Rafael Weingärtner
