PUBLIC - Liferay Portal Community Edition
  1. PUBLIC - Liferay Portal Community Edition
  2. LPS-22541

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

          Activity

          Hide
          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
          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

            • Assignee:
              Sophia Zhang
              Reporter:
              Sophia Zhang
              Recent user:
              Randy Zhu
              Participants of an Issue:
            • Votes:
              0 Vote for this issue
              Watchers:
              0 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:
                Days since last comment:
                3 years, 35 weeks, 1 day ago

                Development

                  Structure Helper Panel