Look at this point:
"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"
I could not find the stacktrace into the logs you provided. But, it has to
have some stack which would help to understand why the CS is not getting up.
This is a good point to look at:
"SEVERE: The addressing-1.5.4.mar module, which is not valid, caused The
module.xml file cannot be found for the module:
/usr/share/cloudstack-management/webapps7080/awsapi/WEB-INF/modules/addressing-1.5.4.mar
org.apache.axis2.deployment.DeploymentException: The module.xml file cannot
be found for the module:
/usr/share/cloudstack-management/webapps7080/awsapi/WEB-INF/modules/addressing-1.5.4.mar
at
org.apache.axis2.deployment.repository.util.ArchiveReader.readModuleArchive(ArchiveReader.java:529)
at
org.apache.axis2.deployment.ModuleDeployer.deploy(ModuleDeployer.java:75)
at
org.apache.axis2.deployment.repository.util.DeploymentFileData.deploy(DeploymentFileData.java:136)
at
org.apache.axis2.deployment.DeploymentEngine.doDeploy(DeploymentEngine.java:661)"
It seems there is a .xml file being missing.
But, still even though the awsapi is not working, the CS app should run
just fine, unless it depends on that service.
This is also something interesting:
"Jun 10, 2014 2:12:58 PM org.apache.catalina.loader.WebappClassLoader
loadClass
INFO: Illegal access: this web application instance has been stopped
already. Could not load
org.apache.cloudstack.managed.context.ManagedContextTimerTask$1. The
eventual following stack trace is caused by an error thrown for debugging
purposes as well as to attempt to terminate the thread which caused the
illegal access, and has no functional impact.
java.lang.IllegalStateException
at
org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1369)"
it seems there is a missing dependency.
BTW: out of curiosity, what do tou have in folder
"/usr/share/cloudstack-management/webapps"
On Tue, Jun 10, 2014 at 3:53 PM, Steve Searles <ssear...@zimcom.net> wrote:
> Nothing interesting in the management server logs, you saw the complete
> ones I sent yesterday. I have attached the complete catalina.out below.
> This is starting to feel like a problem with the DB locking the tables
> during the startup integrity check. I am able to lock the tables via the
> command line with the bin log enabled without issue though.
>
> https://dl.dropboxusercontent.com/u/51895629/catalina.binlog.gz
>
> Steve Searles
>
>
> On Jun 10, 2014, at 2:29 PM, Rafael Weingartner <
> rafaelweingart...@gmail.com> wrote:
>
> this is interesting:
> "
> Jun 10, 2014 2:12:48 PM org.apache.catalina.core.StandardContext start
> SEVERE: Context [/client] startup failed due to previous error"
>
> does it have any extra log before that message?
> Did you find anything at /var/log/cloudstack/management-server.log?
>
>
> On Tue, Jun 10, 2014 at 3:24 PM, Steve Searles <ssear...@zimcom.net>
> wrote:
>
> 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 ]
>
>
>
>
> On Jun 10, 2014, at 10:30 AM, Rafael Weingartner <
> 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>
> 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> 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>
>
> 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 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 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 <ssear...@zimcom.net> <
> ssear...@zimcom.net>]
> Sent: Monday, June 9, 2014 10:19 PM
> To: 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
>
>
>
>
>
> --
> Rafael Weingärtner
>
>
>
--
Rafael Weingärtner
