[Building Sakai] [Deploying Sakai] Tomcat process fails to terminate cleanly after adding kaltura integration

Tom Hall thall at brocku.ca
Tue Oct 2 12:50:23 PDT 2012


Hi Everyone

Thanks for the input.  I Having read all the information provided 
(including the related links), I can see why this is not an easy one to 
solve and why the suggestions of putting a kill -9 after a delay.

I followed Aaron's suggestion and did a ps -3 after the shutdown should 
have completed.  The results are shown below.  The only non-daemon ones 
I see are those I would expect to be among the last threads to exit 
(GC).  The one I find most interesting is the one labeled 
'pool-2-thread-1' being as I have no ideea what it is supposed to be doing.

I also notice that both the reference Handler and Presence threads 
(daemons) that other have mentioned are also in the list of threads 
still in the VM.

Tom


2012-10-02 15:37:07
Full thread dump Java HotSpot(TM) 64-Bit Server VM (20.0-b11 mixed mode):

"DestroyJavaVM" prio=10 tid=0x00007f71f4a41000 nid=0x39b9 waiting on 
condition [0x0000000000000000]
    java.lang.Thread.State: RUNNABLE

"TP-Processor4" daemon prio=10 tid=0x00007f7282ef8000 nid=0x3a1f in 
Object.wait() [0x00007f71eefee000]
    java.lang.Thread.State: WAITING (on object monitor)
     at java.lang.Object.wait(Native Method)
     - waiting on <0x000000009acd0118> (a 
org.apache.jk.common.ChannelSocket)
     at java.lang.Object.wait(Object.java:485)
     at org.apache.jk.common.ChannelSocket.accept(ChannelSocket.java:306)
     - locked <0x000000009acd0118> (a org.apache.jk.common.ChannelSocket)
     at 
org.apache.jk.common.ChannelSocket.acceptConnections(ChannelSocket.java:667)
     at 
org.apache.jk.common.ChannelSocket$SocketAcceptor.runIt(ChannelSocket.java:878)
     at 
org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:689)
     at java.lang.Thread.run(Thread.java:662)

"http-8080-Processor24" daemon prio=10 tid=0x00007f7282a3d800 nid=0x3a19 
waiting on condition [0x00007f71ef5f4000]
    java.lang.Thread.State: TIMED_WAITING (sleeping)
     at java.lang.Thread.sleep(Native Method)
     at 
org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:62)
     at 
org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:689)
     at java.lang.Thread.run(Thread.java:662)

"pool-2-thread-1" prio=10 tid=0x00007f71f4a5c000 nid=0x3a00 waiting on 
condition [0x00007f724cf52000]
    java.lang.Thread.State: WAITING (parking)
     at sun.misc.Unsafe.park(Native Method)    - parking to wait for  
<0x00000000b8234d10> (a 
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
     at 
java.util.concurrent.locks.LockSupport.park(LockSupport.java:158) at 
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)
     at java.util.concurrent.DelayQueue.take(DelayQueue.java:160)    at 
java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:609) 
at 
java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:602)
     at 
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:947) 
at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
     at java.lang.Thread.run(Thread.java:662)
"SakaiPresenceService.Maintenance" daemon prio=10 tid=0x00007f72820f2800 
nid=0x39f6 waiting on condition [0x00007f724d55c000]
    java.lang.Thread.State: TIMED_WAITING (sleeping)
     at java.lang.Thread.sleep(Native Method)
     at 
org.sakaiproject.presence.impl.BasePresenceService$Maintenance.run(BasePresenceService.java:791)
     at java.lang.Thread.run(Thread.java:662)
"org.azeckoski.reflectutils.refmap.Finalizer" daemon prio=10 
tid=0x00007f7282066800 nid=0x39dd in Object.wait() [0x00007f7268cc8000]
    java.lang.Thread.State: WAITING (on object monitor)
     at java.lang.Object.wait(Native Method)
     - waiting on <0x00000000adfcce28> (a java.lang.ref.ReferenceQueue$Lock)
     at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
     - locked <0x00000000adfcce28> (a java.lang.ref.ReferenceQueue$Lock)
     at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:134)
     at org.azeckoski.reflectutils.refmap.Finalizer.run(Finalizer.java:127)
"MySQL Statement Cancellation Timer" daemon prio=10 
tid=0x00007f7282d14000 nid=0x39c9 in Object.wait() [0x00007f72696d2000]
    java.lang.Thread.State: WAITING (on object monitor)
     at java.lang.Object.wait(Native Method)
     - waiting on <0x00000000a97fc548> (a java.util.TaskQueue)
     at java.lang.Object.wait(Object.java:485)
     at java.util.TimerThread.mainLoop(Timer.java:483)
     - locked <0x00000000a97fc548> (a java.util.TaskQueue)
     at java.util.TimerThread.run(Timer.java:462)

"Low Memory Detector" daemon prio=10 tid=0x00007f728011e000 nid=0x39c6 
runnable [0x0000000000000000]
    java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" daemon prio=10 tid=0x00007f728011b800 nid=0x39c5 
waiting on condition [0x0000000000000000]
    java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" daemon prio=10 tid=0x00007f7280119800 nid=0x39c4 
waiting on condition [0x0000000000000000]
    java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=10 tid=0x00007f7280117800 nid=0x39c3 
waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE
"Surrogate Locker Thread (Concurrent GC)" daemon prio=10 
tid=0x00007f7280115800 nid=0x39c2 waiting on condition [0x0000000000000000]
    java.lang.Thread.State: RUNNABLE
"Finalizer" daemon prio=10 tid=0x00007f72800f8800 nid=0x39c1 in 
Object.wait() [0x00007f726ad4d000]
    java.lang.Thread.State: WAITING (on object monitor)
     at java.lang.Object.wait(Native Method)
     - waiting on <0x00000000a825fc48> (a java.lang.ref.ReferenceQueue$Lock)
     at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
     - locked <0x00000000a825fc48> (a java.lang.ref.ReferenceQueue$Lock)
     at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:134)    
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

"Reference Handler" daemon prio=10 tid=0x00007f72800f6800 nid=0x39c0 in 
Object.wait() [0x00007f726ae4e000]
    java.lang.Thread.State: WAITING (on object monitor)
     at java.lang.Object.wait(Native Method)
     - waiting on <0x00000000a8310d10> (a java.lang.ref.Reference$Lock)
     at java.lang.Object.wait(Object.java:485)
     at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
     - locked <0x00000000a8310d10> (a java.lang.ref.Reference$Lock)
"VM Thread" prio=10 tid=0x00007f72800f0000 nid=0x39bf runnable

"Gang worker#0 (Parallel GC Threads)" prio=10 tid=0x00007f7280016000 
nid=0x39ba runnable

"Gang worker#1 (Parallel GC Threads)" prio=10 tid=0x00007f7280018000 
nid=0x39bb runnable

"Gang worker#2 (Parallel GC Threads)" prio=10 tid=0x00007f7280019800 
nid=0x39bc runnable

"Gang worker#3 (Parallel GC Threads)" prio=10 tid=0x00007f728001b800 
nid=0x39bd runnable

"Concurrent Mark-Sweep GC Thread" prio=10 tid=0x00007f72800aa800 
nid=0x39be runnable
"VM Periodic Task Thread" prio=10 tid=0x00007f7280129800 nid=0x39c7 
waiting on condition

JNI global references: 1739

Heap
  par new generation   total 176960K, used 77820K [0x0000000090000000, 
0x000000009c000000, 0x00000000a8000000)
   eden space 157312K,  36% used [0x0000000090000000, 
0x00000000938cf3f0, 0x00000000999a0000)
   from space 19648K, 100% used [0x000000009acd0000, 0x000000009c000000, 
0x000000009c000000)
   to   space 19648K,   0% used [0x00000000999a0000, 0x00000000999a0000, 
0x000000009acd0000) concurrent mark-sweep generation total 589824K, used 
317476K [0x00000000a8000000, 0x00000000cc000000, 0x00000000d0000000) 
concurrent-mark-sweep perm gen total 397300K, used 258847K 
[0x00000000d0000000, 0x00000000e83fd000, 0x0000000100000000)


On 10/2/2012 12:55 PM, Mike De Simone wrote:
> we typically script the shutdown as follows in order to implement a 
> definitive unattended stop of tomcat:
>
> - call kill -3 on tomcat pid to capture a thread dump just before shutdown
> - call shutdown.sh
> - wait about 30 seconds to allow anything that can finish normally to 
> do so (this value depends upon the speed of your server and how much 
> load is on tomcat at the time) and can vary from about 15-45s in my 
> experience)
> - kill -9 to make sure it's stopped.
>
> I don't recommend using the SIGKILL (-9) immediately for production 
> environments.  You could add another kill -3 after the 30 second wait 
> to capture information as Aaron suggests.
>
>
> Thanks,
>
> -------------------------------
> Mike DeSimone
> Application Operations Manager
> *r**Smart* | 602-490-0473
>
>
> On Tue, Oct 2, 2012 at 8:20 AM, Aaron Zeckoski <azeckoski at unicon.net 
> <mailto:azeckoski at unicon.net>> wrote:
>
>     We don't have any annotation scanning going on in the kaltura code.
>     You might want to try doing the shutdown while still tailing the logs
>     and then trying a "kill -3 {pid}" where the pid is the process id
>     (from something like ps) of the tomcat server. This will cause a dump
>     in the tomcat log of the JVM thread. If you wait a little while
>     longer, it will sometimes show other info (because the thing holding
>     stuff up might eventually die after some long timeouts).
>
>     You want to look for threads in there which are NOT daemons. For
>     example, this is a daemon so you can ignore it because the JVM will
>     generally terminate daemons without any hesitation:
>     "org.azeckoski.reflectutils.refmap.Finalizer" daemon prio=5
>     tid=1093f4800 nid=0x10c64a000 in Object.wait() [10c649000]
>        java.lang.Thread.State: WAITING (on object monitor)
>     .....
>
>     On the other hand, something like this is not a daemon thread:
>     "pool-1-thread-1" prio=5 tid=101c54000 nid=0x116a93000 waiting on
>     condition [116a92000]
>        java.lang.Thread.State: WAITING (parking)
>             at sun.misc.Unsafe.park(Native Method)
>             - parking to wait for  <7c6fd3ea8> (a
>     java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
>             at
>     java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)
>             at
>     java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)
>             at java.util.concurrent.DelayQueue.take(DelayQueue.java:160)
>             at
>     java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:609)
>             at
>     java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:602)
>
>
>     Normally the one (or two) non-daemon threads are the culprits that are
>     keeping things from shutting down properly.
>
>     -AZ
>
>
>     On Tue, Oct 2, 2012 at 7:23 AM, Brian Baillargeon <bbailla2 at uwo.ca
>     <mailto:bbailla2 at uwo.ca>> wrote:
>     > For me, the thread issues in Certification went away when I removed
>     > '@resource' annotations and implemented them with
>     ComponentManager. So,
>     > I'm not sure if it's an issue with @resource annotations in
>     spring-mvc
>     > projects or something else. Anyway, I just grepped unicon's kaltura
>     > source and didn't find any @resource annotations, but personally
>     I'd try
>     > removing some annotations first and see if the thread stops that
>     way.
>     >
>     > On 12-10-02 09:19 AM, Mike Jennings wrote:
>     >> Tom,
>     >>
>     >> A few people have had this issue with Tomcat not shutting down
>     properly.
>     >>    It appears that some magic combination of tools causes a
>     specific
>     >> thread to hang.  Here at UNC when we had the gradebook2 module
>     installed
>     >> this issue would happen and then when we removed this tool it
>     >> immediately went away.
>     >>
>     >> You can take a look at this thread here where there was a lot of
>     >> discussion on this issue.
>     >>
>     >>
>     http://sakai-project-mail-list-archives.1343168.n2.nabble.com/Building-Sakai-Tomcat-not-shutting-down-properly-td7410135.html
>     >>
>     >>
>     >> Mike
>     >>
>     >>
>     ==============================================================================
>     >> Mike Jennings
>     >> Teaching and Learning Developer
>     >> University of North Carolina at Chapel Hill
>     >>
>     >> Office: (919) 843-5013 <tel:%28919%29%20843-5013>
>     >> Cell: (919) 698-3746 <tel:%28919%29%20698-3746>
>     >> E-mail: mike_jennings at unc.edu <mailto:mike_jennings at unc.edu>
>     >>
>     >> On 10/2/2012 8:51 AM, Tom Hall wrote:
>     >>> Hi Everyone
>     >>>
>     >>> We have just incorporated the Kaltura integration module into
>     our 2.8.x
>     >>> (source downloaded June 2011 with many mods) development and test
>     >>> environments.  Everything appears to work OK except that the
>     <tomcat
>     >>> home>/bin/shutdown.sh script no longer stops the tomcat
>     process.  The
>     >>> catalina.out log file shows the usual last line of :
>     >>>
>     >>>     INFO main org.apache.coyote.http11.Http11BaseProtocol -
>     Stopping
>     >>> Coyote HTTP/1.1 on http-8080
>     >>>
>     >>> and there are no errors during the shutdown process.
>     >>>
>     >>> Has anyone seen anything like this before.
>     >>>
>     >>> Thanks
>     >>>
>     >>> Tom
>     >>> _______________________________________________
>     >>> sakai-dev mailing list
>     >>> sakai-dev at collab.sakaiproject.org
>     <mailto:sakai-dev at collab.sakaiproject.org>
>     >>> http://collab.sakaiproject.org/mailman/listinfo/sakai-dev
>     >>>
>     >>> TO UNSUBSCRIBE: send email to
>     sakai-dev-unsubscribe at collab.sakaiproject.org
>     <mailto:sakai-dev-unsubscribe at collab.sakaiproject.org> with a
>     subject of "unsubscribe"
>     >>>
>     >> _______________________________________________
>     >> sakai-dev mailing list
>     >> sakai-dev at collab.sakaiproject.org
>     <mailto:sakai-dev at collab.sakaiproject.org>
>     >> http://collab.sakaiproject.org/mailman/listinfo/sakai-dev
>     >>
>     >> TO UNSUBSCRIBE: send email to
>     sakai-dev-unsubscribe at collab.sakaiproject.org
>     <mailto:sakai-dev-unsubscribe at collab.sakaiproject.org> with a
>     subject of "unsubscribe"
>     >
>     > _______________________________________________
>     > sakai-dev mailing list
>     > sakai-dev at collab.sakaiproject.org
>     <mailto:sakai-dev at collab.sakaiproject.org>
>     > http://collab.sakaiproject.org/mailman/listinfo/sakai-dev
>     >
>     > TO UNSUBSCRIBE: send email to
>     sakai-dev-unsubscribe at collab.sakaiproject.org
>     <mailto:sakai-dev-unsubscribe at collab.sakaiproject.org> with a
>     subject of "unsubscribe"
>
>
>
>     --
>     Aaron Zeckoski - Software Architect - http://tinyurl.com/azprofile
>     _______________________________________________
>     production mailing list
>     production at collab.sakaiproject.org
>     <mailto:production at collab.sakaiproject.org>
>     http://collab.sakaiproject.org/mailman/listinfo/production
>
>     TO UNSUBSCRIBE: send email to
>     production-unsubscribe at collab.sakaiproject.org
>     <mailto:production-unsubscribe at collab.sakaiproject.org> with a
>     subject of "unsubscribe"
>
>
>
>
> _______________________________________________
> sakai-dev mailing list
> sakai-dev at collab.sakaiproject.org
> http://collab.sakaiproject.org/mailman/listinfo/sakai-dev
>
> TO UNSUBSCRIBE: send email to sakai-dev-unsubscribe at collab.sakaiproject.org with a subject of "unsubscribe"

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://collab.sakaiproject.org/pipermail/sakai-dev/attachments/20121002/913d3ab8/attachment.html 


More information about the sakai-dev mailing list