tomcat-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Yann Rouillard <yann.rouill...@jouy.inra.fr>
Subject Re: High CPU Usage with Apache Portable Runtime
Date Thu, 21 Sep 2006 14:08:39 GMT
Using Dtrace , I tried to gather some more information.
Here is the output of a Dtrace script called dapptrace.

It confirms the fact that the tomcat thread spends its cpu time in the 
Poll functions however I still don't understand why listening to events 
on port can't use so much cpu.
Any hint or clue on how I could understand the reason of this behaviour ?


PID/LWP   RELATIVE  ELAPSD    CPU CALL(args)             = return
1736/16:   5211128       .      .                           -> 
libtcnative-1.so.0.1.3:Java_org_apache_tomcat_jni_Poll_poll(0x876717C, 
0xD4CCFC44, 0x8
7086B8)
21736/16:   5211131       .      .                             -> 
libapr-1.so.0.2.7:apr_pollset_poll(0x86BD6E0, 0x7D0, 0x0)
21736/16:   5211133       .      .                               -> 
libc.so.1:__div64(0x7D0, 0x0, 0xF4240)
21736/16:   5211134       .      .                                 -> 
libc.so.1:divmod64(0xD8FF5680, 0xD5208246, 0x7D0)
21736/16:   5211134      13      0                                 <- 
libc.so.1:divmod64 = 48
21736/16:   5211135      37      2                               <- 
libc.so.1:__div64 = 47
21736/16:   5211136       .      .                               -> 
libc.so.1:__div64(0x7D0, 0x0, 0x3E8)
21736/16:   5211136       .      .                                 -> 
libc.so.1:divmod64(0xD8FF5680, 0xD5208265, 0x7D0)
21736/16:   5211137      13      0                                 <- 
libc.so.1:divmod64 = 48
21736/16:   5211137      36      1                               <- 
libc.so.1:__div64 = 47
21736/16:   5211138       .      .                               -> 
libc.so.1:__rem64(0x2, 0x0, 0x3E8)
21736/16:   5211139       .      .                                 -> 
libc.so.1:divmod64(0x2, 0xD520827D, 0x2)
21736/16:   5211140      13      0                                 <- 
libc.so.1:divmod64 = 48
21736/16:   5211140      37      2                               <- 
libc.so.1:__rem64 = 88
21736/16:   5211143       .      .                               -> 
libc.so.1:port_getn(0x17, 0x86BF6B0, 0x2000)
21736/16:   5211145       .      .                                 -> 
libc.so.1:_portfs(0x6, 0x17, 0x86BF6B0)
21736/16:   5211150      19      5                                 <- 
libc.so.1:_portfs = 13
21736/16:   5211151       .      .                                 -> 
libc.so.1:___errno(0x86BD6E0, 0xD522284C, 0x0)
21736/16:   5211151      13      0                                 <- 
libc.so.1:___errno = 32
21736/16:   5211152      68      9                               <- 
libc.so.1:port_getn = 112
21736/16:   5211153       .      .                               -> 
libc.so.1:___errno(0x7D0, 0xD8FF5680, 0xD52749E4)
21736/16:   5211153      12      0                               <- 
libc.so.1:___errno = 32
21736/16:   5211154     261     22                             <- 
libapr-1.so.0.2.7:apr_pollset_poll = 1297
21736/16:   5211154     295     25                           <- 
libtcnative-1.so.0.1.3:Java_org_apache_tomcat_jni_Poll_poll = 525

Yann

Yann Rouillard a écrit :
> Yes from what I understand a native call is used when you use the apache 
> portable runtime with tomcat.
> 
> Yann
> 
> David Delbecq a écrit :
>> Nice, in a native call :/
>>
>> "ajp-8009-Poller-0" daemon prio=5 tid=0x087670e0 nid=0x10 runnable
>> [0xd4ccf000..0xd4ccfd98]
>>     at org.apache.tomcat.jni.Poll.poll(Native Method)
>>     at
>> org.apache.tomcat.util.net.AprEndpoint$Poller.run(AprEndpoint.java:1153)
>>     at java.lang.Thread.run(Thread.java:534)
>>
>> can't help you then :)
>>
>> Yann Rouillard a écrit :
>>> Here is the jvm thread dump:
>>>
>>> Full thread dump Java HotSpot(TM) Client VM (1.4.2_11-b06 mixed mode):
>>>
>>> "ajp-8009-3" daemon prio=5 tid=0x083ee530 nid=0x12 in Object.wait()
>>> [0xd4c4b000..0xd4c4bd98]
>>>     at java.lang.Object.wait(Native Method)
>>>     - waiting on <0xd5e5c1f8> (a
>>> org.apache.tomcat.util.net.AprEndpoint$Worker)
>>>     at java.lang.Object.wait(Object.java:429)
>>>     at
>>> org.apache.tomcat.util.net.AprEndpoint$Worker.await(AprEndpoint.java:1255) 
>>>
>>>
>>>     - locked <0xd5e5c1f8> (a
>>> org.apache.tomcat.util.net.AprEndpoint$Worker)
>>>     at
>>> org.apache.tomcat.util.net.AprEndpoint$Worker.run(AprEndpoint.java:1280)
>>>     at java.lang.Thread.run(Thread.java:534)
>>>
>>> "ajp-8009-2" daemon prio=5 tid=0x087813b0 nid=0x11 in Object.wait()
>>> [0xd4c8d000..0xd4c8dd98]
>>>     at java.lang.Object.wait(Native Method)
>>>     - waiting on <0xd62a0060> (a
>>> org.apache.tomcat.util.net.AprEndpoint$Worker)
>>>     at java.lang.Object.wait(Object.java:429)
>>>     at
>>> org.apache.tomcat.util.net.AprEndpoint$Worker.await(AprEndpoint.java:1255) 
>>>
>>>
>>>     - locked <0xd62a0060> (a
>>> org.apache.tomcat.util.net.AprEndpoint$Worker)
>>>     at
>>> org.apache.tomcat.util.net.AprEndpoint$Worker.run(AprEndpoint.java:1280)
>>>     at java.lang.Thread.run(Thread.java:534)
>>>
>>> "ajp-8009-Poller-0" daemon prio=5 tid=0x087670e0 nid=0x10 runnable
>>> [0xd4ccf000..0xd4ccfd98]
>>>     at org.apache.tomcat.jni.Poll.poll(Native Method)
>>>     at
>>> org.apache.tomcat.util.net.AprEndpoint$Poller.run(AprEndpoint.java:1153)
>>>     at java.lang.Thread.run(Thread.java:534)
>>>
>>> "ajp-8009-1" daemon prio=5 tid=0x087646c0 nid=0xf in Object.wait()
>>> [0xd4d11000..0xd4d11d98]
>>>     at java.lang.Object.wait(Native Method)
>>>     - waiting on <0xd906b2c0> (a
>>> org.apache.tomcat.util.net.AprEndpoint$Worker)
>>>     at java.lang.Object.wait(Object.java:429)
>>>     at
>>> org.apache.tomcat.util.net.AprEndpoint$Worker.await(AprEndpoint.java:1255) 
>>>
>>>
>>>     - locked <0xd906b2c0> (a
>>> org.apache.tomcat.util.net.AprEndpoint$Worker)
>>>     at
>>> org.apache.tomcat.util.net.AprEndpoint$Worker.run(AprEndpoint.java:1280)
>>>     at java.lang.Thread.run(Thread.java:534)
>>>
>>> "ajp-8009-Acceptor-0" daemon prio=5 tid=0x086bd478 nid=0xe runnable
>>> [0xd4d53000..0xd4d53d98]
>>>     at org.apache.tomcat.jni.Socket.accept(Native Method)
>>>     at
>>> org.apache.tomcat.util.net.AprEndpoint$Acceptor.run(AprEndpoint.java:999) 
>>>
>>>     at java.lang.Thread.run(Thread.java:534)
>>>
>>> "http-8080-1" daemon prio=5 tid=0x086b98d0 nid=0xd in Object.wait()
>>> [0xd4d95000..0xd4d95d98]
>>>     at java.lang.Object.wait(Native Method)
>>>     - waiting on <0xd8ff0bb8> (a
>>> org.apache.tomcat.util.net.AprEndpoint$Worker)
>>>     at java.lang.Object.wait(Object.java:429)
>>>     at
>>> org.apache.tomcat.util.net.AprEndpoint$Worker.await(AprEndpoint.java:1255) 
>>>
>>>
>>>     - locked <0xd8ff0bb8> (a
>>> org.apache.tomcat.util.net.AprEndpoint$Worker)
>>>     at
>>> org.apache.tomcat.util.net.AprEndpoint$Worker.run(AprEndpoint.java:1280)
>>>     at java.lang.Thread.run(Thread.java:534)
>>>
>>> "http-8080-Sendfile-0" daemon prio=5 tid=0x083cf830 nid=0xc in
>>> Object.wait() [0xd4dd7000..0xd4dd7d98]
>>>     at java.lang.Object.wait(Native Method)
>>>     - waiting on <0xd8ff0c20> (a
>>> org.apache.tomcat.util.net.AprEndpoint$Sendfile)
>>>     at java.lang.Object.wait(Object.java:429)
>>>     at
>>> org.apache.tomcat.util.net.AprEndpoint$Sendfile.run(AprEndpoint.java:1486) 
>>>
>>>
>>>     - locked <0xd8ff0c20> (a
>>> org.apache.tomcat.util.net.AprEndpoint$Sendfile)
>>>     at java.lang.Thread.run(Thread.java:534)
>>>
>>> "http-8080-Poller-0" daemon prio=5 tid=0x083c4eb0 nid=0xb in
>>> Object.wait() [0xd4e19000..0xd4e19d98]
>>>     at java.lang.Object.wait(Native Method)
>>>     - waiting on <0xd8ff0c98> (a
>>> org.apache.tomcat.util.net.AprEndpoint$Poller)
>>>     at java.lang.Object.wait(Object.java:429)
>>>     at
>>> org.apache.tomcat.util.net.AprEndpoint$Poller.run(AprEndpoint.java:1127)
>>>     - locked <0xd8ff0c98> (a
>>> org.apache.tomcat.util.net.AprEndpoint$Poller)
>>>     at java.lang.Thread.run(Thread.java:534)
>>>
>>> "http-8080-Acceptor-0" daemon prio=5 tid=0x083a1d58 nid=0xa runnable
>>> [0xd4e5b000..0xd4e5bd98]
>>>     at org.apache.tomcat.jni.Socket.accept(Native Method)
>>>     at
>>> org.apache.tomcat.util.net.AprEndpoint$Acceptor.run(AprEndpoint.java:999) 
>>>
>>>     at java.lang.Thread.run(Thread.java:534)
>>>
>>> "ContainerBackgroundProcessor[StandardEngine[Catalina]]" daemon prio=5
>>> tid=0x0839d4b8 nid=0x9 waiting on condition [0xd4e9d000..0xd4e9dd98]
>>>     at java.lang.Thread.sleep(Native Method)
>>>     at
>>> org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.run(ContainerBase.java:1547)

>>>
>>>
>>>     at java.lang.Thread.run(Thread.java:534)
>>>
>>> "Signal Dispatcher" daemon prio=10 tid=0x08116e10 nid=0x6 waiting on
>>> condition [0x00000000..0x00000000]
>>>
>>> "Finalizer" daemon prio=8 tid=0x0810fba0 nid=0x4 in Object.wait()
>>> [0xfc06d000..0xfc06dd98]
>>>     at java.lang.Object.wait(Native Method)
>>>     - waiting on <0xd85bb9d0> (a java.lang.ref.ReferenceQueue$Lock)
>>>     at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:111)
>>>     - locked <0xd85bb9d0> (a java.lang.ref.ReferenceQueue$Lock)
>>>     at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:127)
>>>     at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)
>>>
>>> "Reference Handler" daemon prio=10 tid=0x0810f188 nid=0x3 in
>>> Object.wait() [0xfc0cc000..0xfc0ccd98]
>>>     at java.lang.Object.wait(Native Method)
>>>     - waiting on <0xd85bba38> (a java.lang.ref.Reference$Lock)
>>>     at java.lang.Object.wait(Object.java:429)
>>>     at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:115)
>>>     - locked <0xd85bba38> (a java.lang.ref.Reference$Lock)
>>>
>>> "main" prio=5 tid=0x080741c8 nid=0x1 runnable [0x08046000..0x08046ed0]
>>>     at java.net.PlainSocketImpl.socketAccept(Native Method)
>>>     at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:353)
>>>     - locked <0xd62a0418> (a java.net.PlainSocketImpl)
>>>     at java.net.ServerSocket.implAccept(ServerSocket.java:448)
>>>     at java.net.ServerSocket.accept(ServerSocket.java:419)
>>>     at
>>> org.apache.catalina.core.StandardServer.await(StandardServer.java:388)
>>>     at org.apache.catalina.startup.Catalina.await(Catalina.java:615)
>>>     at org.apache.catalina.startup.Catalina.start(Catalina.java:575)
>>>     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:324)
>>>     at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:294)
>>>     at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:432)
>>>
>>> "VM Thread" prio=5 tid=0x0810e340 nid=0x2 runnable
>>>
>>> "VM Periodic Task Thread" prio=10 tid=0x08118988 nid=0x8 waiting on
>>> condition
>>> "Suspend Checker Thread" prio=10 tid=0x081164a8 nid=0x5 runnable
>>>
>>>
>>>
>>> David Delbecq a écrit :
>>>> Could you send us a few jvm thread dumps while the CPU usage, i bet 
>>>> this
>>>> an be more helpful than an os dump.
>>>> To generate a Thread dump, simply send the signal 3 to the java process
>>>> (assuming you use a SUN jvm or derivative)
>>>>
>>>> Yann Rouillard a écrit :
>>>>>>>> Did you tried it with Tomcat 5.5.17?
>>>>>>> No but I can try. Some modifications have been on this area ?
>>>>>>>
>>>>>> Yes, a lots of them, see the:
>>>>>> http://tomcat.apache.org/tomcat-5.5-doc/changelog.html
>>>>>>
>>>>>> The way how Poller is handled has changed, so just try the
>>>>>> 5.5.17.
>>>>> Ok, I have tried with 5.5.17 and the problem is still present.
>>>>> The thread using the CPU is still the thread doing the polling:
>>>>>
>>>>> -----------------  lwp# 16 / thread# 16  --------------------
>>>>>  fef3fff7 portfs   (6, 17, 86bf6b0, 2000, 1, d4ccfbb4)
>>>>>  d52083d6 apr_pollset_poll (86bd6e0, 7d0, 0, d4ccfc04, d4ccfc10) + 1fe
>>>>>  d524ccec Java_org_apache_tomcat_jni_Poll_poll (876717c, d4ccfc44,
>>>>> 87086b8, 0, 7d0, 0) + 64
>>>>>
>>>>>
>>>>> Yann
>>>>>
>>>>>
>>>>>
>>>>> ---------------------------------------------------------------------
>>>>> To start a new topic, e-mail: users@tomcat.apache.org
>>>>> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
>>>>> For additional commands, e-mail: users-help@tomcat.apache.org
>>>>>
>>>>
>>>> ---------------------------------------------------------------------
>>>> To start a new topic, e-mail: users@tomcat.apache.org
>>>> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
>>>> For additional commands, e-mail: users-help@tomcat.apache.org
>>>>
>>>
>>> ---------------------------------------------------------------------
>>> To start a new topic, e-mail: users@tomcat.apache.org
>>> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
>>> For additional commands, e-mail: users-help@tomcat.apache.org
>>>
>>
>>
>> ---------------------------------------------------------------------
>> To start a new topic, e-mail: users@tomcat.apache.org
>> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
>> For additional commands, e-mail: users-help@tomcat.apache.org
>>
> 
> 
> ---------------------------------------------------------------------
> To start a new topic, e-mail: users@tomcat.apache.org
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
> 


---------------------------------------------------------------------
To start a new topic, e-mail: users@tomcat.apache.org
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Mime
View raw message