PUBLIC - Liferay Portal Community Edition

Server shut down automatically the second time when starting node2

Details

  • Similar Issues:
    Show 5 results 

Description

1. Start node 1(Enable cluster,configure ehcache using cluster-web plugin + ehcache.cluster.link.replication.enabled=true in ext properties)in machine 1.
2. Start node2.
Everything goes well.
Now shut down node 2 and restart it.You would get the following exceptions.Restart again,success.

E:\Project-trunk\tomcat-7.0.21\bin>catalina.bat run
Using CATALINA_BASE:   "E:\Project-trunk\tomcat-7.0.21"
Using CATALINA_HOME:   "E:\Project-trunk\tomcat-7.0.21"
Using CATALINA_TMPDIR: "E:\Project-trunk\tomcat-7.0.21\temp"
Using JRE_HOME:        "C:\Program Files\Java\jdk1.6.0_24"
Using CLASSPATH:       "E:\Project-trunk\tomcat-7.0.21\bin\bootstrap.jar;E:\Project-trunk\tomcat-7.0.21\bin\tomcat-juli.jar"
2011-10-26 3:31:05 org.apache.catalina.core.AprLifecycleListener init
淇℃伅: The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: C:\Program Files\Java\jdk1.6.0_24\bin;.;C:\Windows\Sun\Java\bin;C:\Windows\system32;C:\Windows;E:\Project-trunk\db-derby-10.6.1.0-bin\bin;D:\MYSQL\bin;C:\Program Files\Java\jdk1.6.0_24\bin;D:\smartsvn\collab\Subversion Client;D:\apache-ant-1.8.1\bin;C:\Program Files\Java\jdk1.6.0_24;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0\;C:;C:\Program Files (x86)\Bitvise Tunnelier;C:\Program Files (x86)\Common Files\Thunder Network\KanKan\Codecs
2011-10-26 3:31:05 org.apache.coyote.AbstractProtocol init
淇℃伅: Initializing ProtocolHandler ["http-bio-9080"]
2011-10-26 3:31:05 org.apache.coyote.AbstractProtocol init
淇℃伅: Initializing ProtocolHandler ["ajp-bio-9009"]
2011-10-26 3:31:05 org.apache.catalina.startup.Catalina load
淇℃伅: Initialization processed in 659 ms
2011-10-26 3:31:05 org.apache.catalina.core.StandardService startInternal
淇℃伅: Starting service Catalina
2011-10-26 3:31:05 org.apache.catalina.core.StandardEngine startInternal
淇℃伅: Starting Servlet Engine: Apache Tomcat/7.0.21
2011-10-26 3:31:05 org.apache.catalina.startup.HostConfig deployDescriptor
淇℃伅: Deploying configuration descriptor ROOT.xml from E:\Project-trunk\tomcat-7.0.21\conf\Catalina\localhost
Loading jar:file:/E:/Project-trunk/tomcat-7.0.21/webapps/ROOT/WEB-INF/lib/portal-impl.jar!/system.properties
03:31:07,535 INFO  [EasyConf:122] Refreshed the configuration of all components
03:31:07,933 INFO  [ConfigurationLoader:56] Properties for jar:file:/E:/Project-trunk/tomcat-7.0.21/webapps/ROOT/WEB-INF/lib/portal-impl.jar!/portal loaded from [file:/E:/Project-trunk/portal-ext.properties, jar:file:/E:/Project-trunk/tomcat-7.0.21/webapps/ROOT/WEB-INF/lib/portal-impl.jar!/portal.properties]
Loading jar:file:/E:/Project-trunk/tomcat-7.0.21/webapps/ROOT/WEB-INF/lib/portal-impl.jar!/portal.properties
Loading file:/E:/Project-trunk/portal-ext.properties
03:31:22,001 INFO  [DialectDetector:80] Determine dialect for MySQL 5
03:31:22,056 INFO  [DialectDetector:145] Found dialect org.hibernate.dialect.MySQLDialect
03:31:56,608 INFO  [ClusterBase:157] Autodetecting JGroups outgoing IP address and interface for www.google.com:80
03:31:56,708 INFO  [ClusterBase:173] Setting JGroups outgoing IP address to 192.168.133.164 and interface to eth3

-------------------------------------------------------------------
GMS: address=sophia-PC-19884, cluster=LIFERAY-CONTROL-CHANNEL, physical address=192.168.133.164:57583
-------------------------------------------------------------------
03:31:57,756 INFO  [ClusterBase:111] Create a new channel with properties UDP(oob_thread_pool_min_threads=2;bind_addr=/192.168.133.164;oob_thread_pool_keep_alive_time=30000;port_range=50;oob_thread_pool_enabled=true;stats=true;max_bundle_size=64000;mcast_send_buf_size=150000;receive_on_all_interfaces=false;diagnostics_addr=/224.0.75.75;mcast_recv_buf_size=80000;tos=8;bind_port=0;oob_thread_pool_rejection_policy=discard;mcast_port=23301;loopback=true;thread_pool_min_threads=2;oob_thread_pool_queue_enabled=true;name=UDP;enable_unicast_bundling=false;thread_pool_keep_alive_time=30000;thread_pool_enabled=true;thread_pool_max_threads=10;enable_diagnostics=true;thread_naming_pattern=cl;ucast_recv_buf_size=64000;ucast_send_buf_size=100000;ip_ttl=8;oob_thread_pool_queue_max_size=500;enable_bundling=true;thread_pool_queue_enabled=true;discard_incompatible_packets=false;use_local_host=false;diagnostics_port=7500;oob_thread_pool_max_threads=10;max_bundle_timeout=20;ip_mcast=true;mcast_gr
oup_addr=/239.255.0.1;bind_interface_str=;marshaller_pool_size=0;log_discard_msgs=true;num_timer_threads=4;thread_pool_queue_max_size=500;thread_pool_rejection_policy=Discard)
:PING(return_entire_cache=false;num_initial_members=3;break_on_coord_rsp=true;stats=true;name=PING;num_ping_requests=2;discovery_timeout=0;timeout=2000;num_initial_srv_members=0)
:MERGE2(stats=true;name=MERGE2;inconsistent_view_threshold=1;min_interval=5000;max_interval=10000)
:FD_SOCK(get_cache_timeout=1000;bind_addr=/192.168.133.164;sock_conn_timeout=1000;bind_interface_str=;stats=true;name=FD_SOCK;suspect_msg_interval=5000;keep_alive=true;start_port=0;num_tries=3)
:VERIFY_SUSPECT(bind_addr=/192.168.133.164;bind_interface_str=;stats=true;name=VERIFY_SUSPECT;num_msgs=1;use_icmp=false;timeout=1500)
:pbcast.NAKACK(gc_lag=50;use_mcast_xmit_req=false;use_mcast_xmit=true;xmit_from_random_member=false;stats=true;retransmit_timeouts=300,600,1200,2400,4800;exponential_backoff=0;log_not_found_msgs=true;enable_xmit_time_stats=false;discard_delivered_msgs=true;print_stability_history_on_failed_xmit=false;use_stats_for_retransmission=false;xmit_history_max_size=50;max_rebroadcast_timeout=2000;name=NAKACK;log_discard_msgs=true;max_xmit_buf_size=0;use_range_based_retransmitter=true)
:UNICAST(max_retransmit_time=60000;loopback=false;stats=true;name=UNICAST;timeout=300,600,1200,2400)
:pbcast.STABLE(desired_avg_gossip=20000;max_bytes=0;stats=true;name=STABLE;stability_delay=6000)
:FRAG(frag_size=8096;stats=true;name=FRAG;max_retained_buffer=70000)
:pbcast.GMS(print_local_addr=true;stats=true;disable_initial_coord=false;max_bundling_time=50;log_collect_msgs=true;resume_task_timeout=10000;print_physical_addrs=true;use_flush_if_present=true;merge_timeout=5000;num_prev_mbrs=50;leave_timeout=5000;view_bundling=true;name=GMS;join_timeout=5000;handle_concurrent_startup=true;view_ack_collection_timeout=2000)


-------------------------------------------------------------------
GMS: address=sophia-PC-61782, cluster=LIFERAY-TRANSPORT-CHANNEL-0, physical address=192.168.133.164:57584
-------------------------------------------------------------------
03:31:58,423 INFO  [ClusterBase:111] Create a new channel with properties UDP(oob_thread_pool_min_threads=2;bind_addr=/192.168.133.164;oob_thread_pool_keep_alive_time=30000;port_range=50;oob_thread_pool_enabled=true;stats=true;max_bundle_size=64000;mcast_send_buf_size=150000;receive_on_all_interfaces=false;diagnostics_addr=/224.0.75.75;mcast_recv_buf_size=80000;tos=8;bind_port=0;oob_thread_pool_rejection_policy=discard;mcast_port=23302;loopback=true;thread_pool_min_threads=2;oob_thread_pool_queue_enabled=true;name=UDP;enable_unicast_bundling=false;thread_pool_keep_alive_time=30000;thread_pool_enabled=true;thread_pool_max_threads=10;enable_diagnostics=true;thread_naming_pattern=cl;ucast_recv_buf_size=64000;ucast_send_buf_size=100000;ip_ttl=8;oob_thread_pool_queue_max_size=500;enable_bundling=true;thread_pool_queue_enabled=true;discard_incompatible_packets=false;use_local_host=false;diagnostics_port=7500;oob_thread_pool_max_threads=10;max_bundle_timeout=20;ip_mcast=true;mcast_gr
oup_addr=/239.255.0.2;bind_interface_str=;marshaller_pool_size=0;log_discard_msgs=true;num_timer_threads=4;thread_pool_queue_max_size=500;thread_pool_rejection_policy=Discard)
:PING(return_entire_cache=false;num_initial_members=3;break_on_coord_rsp=true;stats=true;name=PING;num_ping_requests=2;discovery_timeout=0;timeout=2000;num_initial_srv_members=0)
:MERGE2(stats=true;name=MERGE2;inconsistent_view_threshold=1;min_interval=5000;max_interval=10000)
:FD_SOCK(get_cache_timeout=1000;bind_addr=/192.168.133.164;sock_conn_timeout=1000;bind_interface_str=;stats=true;name=FD_SOCK;suspect_msg_interval=5000;keep_alive=true;start_port=0;num_tries=3)
:VERIFY_SUSPECT(bind_addr=/192.168.133.164;bind_interface_str=;stats=true;name=VERIFY_SUSPECT;num_msgs=1;use_icmp=false;timeout=1500)
:pbcast.NAKACK(gc_lag=50;use_mcast_xmit_req=false;use_mcast_xmit=true;xmit_from_random_member=false;stats=true;retransmit_timeouts=300,600,1200,2400,4800;exponential_backoff=0;log_not_found_msgs=true;enable_xmit_time_stats=false;discard_delivered_msgs=true;print_stability_history_on_failed_xmit=false;use_stats_for_retransmission=false;xmit_history_max_size=50;max_rebroadcast_timeout=2000;name=NAKACK;log_discard_msgs=true;max_xmit_buf_size=0;use_range_based_retransmitter=true)
:UNICAST(max_retransmit_time=60000;loopback=false;stats=true;name=UNICAST;timeout=300,600,1200,2400)
:pbcast.STABLE(desired_avg_gossip=20000;max_bytes=0;stats=true;name=STABLE;stability_delay=6000)
:FRAG(frag_size=8096;stats=true;name=FRAG;max_retained_buffer=70000)
:pbcast.GMS(print_local_addr=true;stats=true;disable_initial_coord=false;max_bundling_time=50;log_collect_msgs=true;resume_task_timeout=10000;print_physical_addrs=true;use_flush_if_present=true;merge_timeout=5000;num_prev_mbrs=50;leave_timeout=5000;view_bundling=true;name=GMS;join_timeout=5000;handle_concurrent_startup=true;view_ack_collection_timeout=2000)

Starting Liferay Portal Community Edition 6.1.0 CE (Paton / Build 6100 / March 24, 2011)
03:32:01,201 INFO  [BaseDB:409] Database does not support case sensitive queries
03:32:01,478 ERROR [JDBCExceptionReporter:234] Deadlock found when trying to get lock; try restarting transaction
03:32:01,486 ERROR [MainServlet:204] com.liferay.portal.kernel.events.ActionException: com.liferay.portal.kernel.scheduler.SchedulerException: Unable to start scheduler
com.liferay.portal.kernel.events.ActionException: com.liferay.portal.kernel.scheduler.SchedulerException: Unable to start scheduler
        at com.liferay.portal.events.StartupAction.run(StartupAction.java:57)
        at com.liferay.portal.servlet.MainServlet.processStartupEvents(MainServlet.java:1302)
        at com.liferay.portal.servlet.MainServlet.init(MainServlet.java:201)
        at javax.servlet.GenericServlet.init(GenericServlet.java:160)
        at org.apache.catalina.core.StandardWrapper.initServlet(StandardWrapper.java:1228)
        at org.apache.catalina.core.StandardWrapper.loadServlet(StandardWrapper.java:1147)
        at org.apache.catalina.core.StandardWrapper.load(StandardWrapper.java:1043)
        at org.apache.catalina.core.StandardContext.loadOnStartup(StandardContext.java:4957)
        at org.apache.catalina.core.StandardContext$3.call(StandardContext.java:5284)
        at org.apache.catalina.core.StandardContext$3.call(StandardContext.java:5279)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
        at java.util.concurrent.FutureTask.run(FutureTask.java:138)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at java.lang.Thread.run(Thread.java:662)
Caused by: com.liferay.portal.kernel.scheduler.SchedulerException: Unable to start scheduler
        at com.liferay.portal.scheduler.ClusterSchedulerEngine.start(ClusterSchedulerEngine.java:423)
        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 com.liferay.portal.spring.aop.ServiceBeanMethodInvocation.proceed(ServiceBeanMethodInvocation.java:112)
        at com.liferay.portal.spring.transaction.TransactionInterceptor.invoke(TransactionInterceptor.java:56)
        at com.liferay.portal.spring.aop.ServiceBeanMethodInvocation.proceed(ServiceBeanMethodInvocation.java:108)
        at com.liferay.portal.spring.aop.ChainableMethodAdvice.invoke(ChainableMethodAdvice.java:59)
        at com.liferay.portal.spring.aop.ServiceBeanMethodInvocation.proceed(ServiceBeanMethodInvocation.java:108)
        at com.liferay.portal.spring.aop.ChainableMethodAdvice.invoke(ChainableMethodAdvice.java:59)
        at com.liferay.portal.spring.aop.ServiceBeanMethodInvocation.proceed(ServiceBeanMethodInvocation.java:108)
        at com.liferay.portal.spring.aop.ChainableMethodAdvice.invoke(ChainableMethodAdvice.java:59)
        at com.liferay.portal.spring.aop.ServiceBeanMethodInvocation.proceed(ServiceBeanMethodInvocation.java:108)
        at com.liferay.portal.spring.aop.ChainableMethodAdvice.invoke(ChainableMethodAdvice.java:59)
        at com.liferay.portal.spring.aop.ServiceBeanMethodInvocation.proceed(ServiceBeanMethodInvocation.java:108)
        at com.liferay.portal.spring.aop.ServiceBeanAopProxy.invoke(ServiceBeanAopProxy.java:211)
        at $Proxy268.start(Unknown Source)
        at com.liferay.portal.kernel.scheduler.SchedulerEngineUtil._start(SchedulerEngineUtil.java:722)
        at com.liferay.portal.kernel.scheduler.SchedulerEngineUtil.start(SchedulerEngineUtil.java:251)
        at com.liferay.portal.events.StartupAction.doRun(StartupAction.java:158)
        at com.liferay.portal.events.StartupAction.run(StartupAction.java:51)
        ... 14 more
Caused by: com.liferay.portal.kernel.exception.SystemException: com.liferay.portal.kernel.dao.orm.ORMException: org.hibernate.exception.LockAcquisitionException: Could not execute JDBC batch update
        at com.liferay.portal.service.persistence.impl.BasePersistenceImpl.processException(BasePersistenceImpl.java:190)
        at com.liferay.portal.service.persistence.LockPersistenceImpl.updateImpl(LockPersistenceImpl.java:347)
        at com.liferay.portal.service.persistence.LockPersistenceImpl.updateImpl(LockPersistenceImpl.java:1)
        at com.liferay.portal.service.persistence.impl.BasePersistenceImpl.update(BasePersistenceImpl.java:254)
        at com.liferay.portal.service.impl.LockLocalServiceImpl.lock(LockLocalServiceImpl.java:190)
        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 com.liferay.portal.spring.aop.ServiceBeanMethodInvocation.proceed(ServiceBeanMethodInvocation.java:112)
        at com.liferay.portal.spring.transaction.TransactionInterceptor.invoke(TransactionInterceptor.java:71)
        at com.liferay.portal.spring.aop.ServiceBeanMethodInvocation.proceed(ServiceBeanMethodInvocation.java:108)
        at com.liferay.portal.spring.aop.ChainableMethodAdvice.invoke(ChainableMethodAdvice.java:59)
        at com.liferay.portal.spring.aop.ServiceBeanMethodInvocation.proceed(ServiceBeanMethodInvocation.java:108)
        at com.liferay.portal.spring.aop.ChainableMethodAdvice.invoke(ChainableMethodAdvice.java:59)
        at com.liferay.portal.spring.aop.ServiceBeanMethodInvocation.proceed(ServiceBeanMethodInvocation.java:108)
        at com.liferay.portal.spring.aop.ChainableMethodAdvice.invoke(ChainableMethodAdvice.java:59)
        at com.liferay.portal.spring.aop.ServiceBeanMethodInvocation.proceed(ServiceBeanMethodInvocation.java:108)
        at com.liferay.portal.spring.aop.ServiceBeanAopProxy.invoke(ServiceBeanAopProxy.java:211)
        at $Proxy43.lock(Unknown Source)
        at com.liferay.portal.service.LockLocalServiceUtil.lock(LockLocalServiceUtil.java:326)
        at com.liferay.portal.scheduler.ClusterSchedulerEngine.lockMemorySchedulerCluster(ClusterSchedulerEngine.java:753)
        at com.liferay.portal.scheduler.ClusterSchedulerEngine.start(ClusterSchedulerEngine.java:417)
        ... 35 more
Caused by: com.liferay.portal.kernel.dao.orm.ORMException: org.hibernate.exception.LockAcquisitionException: Could not execute JDBC batch update
        at com.liferay.portal.dao.orm.hibernate.ExceptionTranslator.translate(ExceptionTranslator.java:30)
        at com.liferay.portal.dao.orm.hibernate.SessionImpl.flush(SessionImpl.java:122)
        at com.liferay.portal.kernel.dao.orm.ClassLoaderSession.flush(ClassLoaderSession.java:218)
        at com.liferay.portal.service.persistence.BatchSessionImpl.update(BatchSessionImpl.java:95)
        at com.liferay.portal.service.persistence.BatchSessionUtil.update(BatchSessionUtil.java:49)
        at com.liferay.portal.service.persistence.LockPersistenceImpl.updateImpl(LockPersistenceImpl.java:342)
        ... 56 more
Caused by: org.hibernate.exception.LockAcquisitionException: Could not execute JDBC batch update
        at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:107)
        at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66)
        at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:275)
        at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:268)
        at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:184)
        at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321)
        at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:51)
        at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1216)
        at com.liferay.portal.dao.orm.hibernate.SessionImpl.flush(SessionImpl.java:119)
        ... 60 more
Caused by: java.sql.BatchUpdateException: Deadlock found when trying to get lock; try restarting transaction
        at com.mysql.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:1257)
        at com.mysql.jdbc.PreparedStatement.executeBatch(PreparedStatement.java:943)
        at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeBatch(NewProxyPreparedStatement.java:1723)
        at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:70)
        at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:268)
        ... 66 more
Stopping the server due to unexpected startup errors

Issue Links

duplicates

Bug - A problem which impairs or prevents the functions of the product. LPS-22698 LockLocalService fails to lock up row as expected

  • Minor - Minor loss of function, or other problem where easy workaround is present.
  • Closed - The issue is considered finished, the resolution is correct. Issues which are not closed can be reopened.

Activity

Ascending order - Click to sort in descending order
Hide
Permalink
Brian Chan added a comment -

Fix was committed in LPS-22698, but please test this ticket. Thx.

Show
Brian Chan added a comment - Fix was committed in LPS-22698 , but please test this ticket. Thx.
Hide
Permalink
Sophia Zhang added a comment -

PASSED Manual Testing following steps in description.

Reproduced on:
Tomcat 7.0.21 + MySQL 5. 6.1.x Revision 91482.
Node 2 would shut down automatically the second time.

Fixed on:
Tomcat 7.0.21 + MySQL 5. 6.1.x Revision 92696.
Now it could startup successfully without any errors the second time.

Show
Sophia Zhang added a comment - PASSED Manual Testing following steps in description. Reproduced on: Tomcat 7.0.21 + MySQL 5. 6.1.x Revision 91482. Node 2 would shut down automatically the second time. Fixed on: Tomcat 7.0.21 + MySQL 5. 6.1.x Revision 92696. Now it could startup successfully without any errors the second time.

People

Vote (0)
Watch (0)

Dates

  • Created:
    Updated:
    Resolved:
    Days since last comment:
    1 year, 28 weeks, 6 days ago