Discussion:
JAIN-SIP Pointers
Matt White
2012-09-13 23:56:26 UTC
Permalink
Just thought I'd give an update on updating the jain-sip

I've put this latest jain-sip in production on 3 system for several weeks now. One 4.2.1 and the other 2 are 4.4

They are working fine and there is no useability issues. However the sipxrest java process pegs at 100%.

Our systems are multi-core so it doesnt affect system usage.

Setting the call control logs to debug dont show any additional detail.

Is there a good way to debug the sipxrest process.

-M
Matt White 08/13/12 12:14 PM >>>
Thanks, you just answered the questions in my last reply!

-M
Attached is a jar file for jain-sip. Replace the jar and tested it out
before posting traces please.

Don't be too nervous - you can always revert.
Douglas Hubler
2012-09-14 00:17:31 UTC
Permalink
Post by Matt White
Just thought I'd give an update on updating the jain-sip
I've put this latest jain-sip in production on 3 system for several weeks
now. One 4.2.1 and the other 2 are 4.4
They are working fine and there is no useability issues. However the
sipxrest java process pegs at 100%.
Our systems are multi-core so it doesnt affect system usage.
Setting the call control logs to debug dont show any additional detail.
Is there a good way to debug the sipxrest process.
there was some way to dump the java thread and by calling kill -3 on
the process and then cat'ing a file descriptor, but i cannot recall
the exact sequence. Anyone recall?
Matt White
2012-09-14 18:42:55 UTC
Permalink
I used jstack to get a dump of the thread.

Contents available on pastebin: http://pastebin.com/qDSFC4HE
Post by Matt White
Just thought I'd give an update on updating the jain-sip
I've put this latest jain-sip in production on 3 system for several weeks
now. One 4.2.1 and the other 2 are 4.4
They are working fine and there is no useability issues. However the
sipxrest java process pegs at 100%.
Our systems are multi-core so it doesnt affect system usage.
Setting the call control logs to debug dont show any additional detail.
Is there a good way to debug the sipxrest process.
there was some way to dump the java thread and by calling kill -3 on
the process and then cat'ing a file descriptor, but i cannot recall
the exact sequence. Anyone recall?
Douglas Hubler
2012-09-14 18:56:34 UTC
Permalink
this is when is was consuming 100% of CPU?
Post by Matt White
I used jstack to get a dump of the thread.
Contents available on pastebin: http://pastebin.com/qDSFC4HE
Post by Matt White
Just thought I'd give an update on updating the jain-sip
I've put this latest jain-sip in production on 3 system for several weeks
now. One 4.2.1 and the other 2 are 4.4
They are working fine and there is no useability issues. However the
sipxrest java process pegs at 100%.
Our systems are multi-core so it doesnt affect system usage.
Setting the call control logs to debug dont show any additional detail.
Is there a good way to debug the sipxrest process.
there was some way to dump the java thread and by calling kill -3 on
the process and then cat'ing a file descriptor, but i cannot recall
the exact sequence. Anyone recall?
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
Matt White
2012-09-14 19:13:31 UTC
Permalink
Yup.

But looking at the stack I dont think it really shows much. I see alot of these: Error occurred during stack walking:

A quick google would show jstack cant always walk the stack when its hung, so I'm not sure its valid.

Its easy to replicate, copy over the jain-sip-sdp and restart call control. Utilization goes to 100%.
Copy the old one back and restart call control and it goes back to normal.

When I have some spare time I might go back through some older releases of jain-sip and see if the issue started at a specific release.

-M
this is when is was consuming 100% of CPU?
Post by Matt White
I used jstack to get a dump of the thread.
Contents available on pastebin: http://pastebin.com/qDSFC4HE
Post by Matt White
Just thought I'd give an update on updating the jain-sip
I've put this latest jain-sip in production on 3 system for several weeks
now. One 4.2.1 and the other 2 are 4.4
They are working fine and there is no useability issues. However the
sipxrest java process pegs at 100%.
Our systems are multi-core so it doesnt affect system usage.
Setting the call control logs to debug dont show any additional detail.
Is there a good way to debug the sipxrest process.
there was some way to dump the java thread and by calling kill -3 on
the process and then cat'ing a file descriptor, but i cannot recall
the exact sequence. Anyone recall?
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
George Niculae
2012-09-14 19:32:38 UTC
Permalink
Try using

jmap -F -dump:file=dump.map PID

Loading in MemoryAnalyzerTool reveals issues

George
Post by Matt White
Yup.
But looking at the stack I dont think it really shows much. I see alot
A quick google would show jstack cant always walk the stack when its
hung, so I'm not sure its valid.
Post by Matt White
Its easy to replicate, copy over the jain-sip-sdp and restart call
control. Utilization goes to 100%.
Post by Matt White
Copy the old one back and restart call control and it goes back to normal.
When I have some spare time I might go back through some older releases
of jain-sip and see if the issue started at a specific release.
Post by Matt White
-M
this is when is was consuming 100% of CPU?
Post by Matt White
I used jstack to get a dump of the thread.
Contents available on pastebin: http://pastebin.com/qDSFC4HE
Post by Matt White
Just thought I'd give an update on updating the jain-sip
I've put this latest jain-sip in production on 3 system for several weeks
now. One 4.2.1 and the other 2 are 4.4
They are working fine and there is no useability issues. However the
sipxrest java process pegs at 100%.
Our systems are multi-core so it doesnt affect system usage.
Setting the call control logs to debug dont show any additional detail.
Is there a good way to debug the sipxrest process.
there was some way to dump the java thread and by calling kill -3 on
the process and then cat'ing a file descriptor, but i cannot recall
the exact sequence. Anyone recall?
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
Alex Mateescu
2012-09-15 14:14:58 UTC
Permalink
kill -3 <pid>, optionally redirected to a file seems to work better than
jstack, though it will show the running threads, not how much CPU they use.
For that, you'd need to connect a profiler (e.g. VisualVM) to the running
process.

Alex
Post by George Niculae
Try using
jmap -F -dump:file=dump.map PID
Loading in MemoryAnalyzerTool reveals issues
George
Post by Matt White
Yup.
But looking at the stack I dont think it really shows much. I see alot
A quick google would show jstack cant always walk the stack when its
hung, so I'm not sure its valid.
Post by Matt White
Its easy to replicate, copy over the jain-sip-sdp and restart call
control. Utilization goes to 100%.
Post by Matt White
Copy the old one back and restart call control and it goes back to
normal.
Post by Matt White
When I have some spare time I might go back through some older releases
of jain-sip and see if the issue started at a specific release.
Post by Matt White
-M
this is when is was consuming 100% of CPU?
Post by Matt White
I used jstack to get a dump of the thread.
Contents available on pastebin: http://pastebin.com/qDSFC4HE
Post by Matt White
Just thought I'd give an update on updating the jain-sip
I've put this latest jain-sip in production on 3 system for several
weeks
Post by Matt White
Post by Matt White
Post by Matt White
now. One 4.2.1 and the other 2 are 4.4
They are working fine and there is no useability issues. However the
sipxrest java process pegs at 100%.
Our systems are multi-core so it doesnt affect system usage.
Setting the call control logs to debug dont show any additional detail.
Is there a good way to debug the sipxrest process.
there was some way to dump the java thread and by calling kill -3 on
the process and then cat'ing a file descriptor, but i cannot recall
the exact sequence. Anyone recall?
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
Matt White
2012-09-15 15:00:31 UTC
Permalink
kill -3 <pid> does not work. I'm not sure if its because the process is stuck but I can use on other java process but not the one stuck at 100%

Thats why i tried jack as its already available on the machine.

-m
kill -3 <pid>, optionally redirected to a file seems to work better than jstack, though it will show the running threads, not how much CPU they use. For that, you'd need to connect a profiler (e.g. VisualVM) to the running process.

Alex

On Fri, Sep 14, 2012 at 10:32 PM, George Niculae <***@ezuce.com> wrote:
Try using

jmap -F -dump:file=dump.map PID

Loading in MemoryAnalyzerTool reveals issues

George
Post by Matt White
Yup.
A quick google would show jstack cant always walk the stack when its hung, so I'm not sure its valid.
Its easy to replicate, copy over the jain-sip-sdp and restart call control. Utilization goes to 100%.
Copy the old one back and restart call control and it goes back to normal.
When I have some spare time I might go back through some older releases of jain-sip and see if the issue started at a specific release.
-M
this is when is was consuming 100% of CPU?
Post by Matt White
I used jstack to get a dump of the thread.
Contents available on pastebin: http://pastebin.com/qDSFC4HE
Post by Matt White
Just thought I'd give an update on updating the jain-sip
I've put this latest jain-sip in production on 3 system for several weeks
now. One 4.2.1 and the other 2 are 4.4
They are working fine and there is no useability issues. However the
sipxrest java process pegs at 100%.
Our systems are multi-core so it doesnt affect system usage.
Setting the call control logs to debug dont show any additional detail.
Is there a good way to debug the sipxrest process.
there was some way to dump the java thread and by calling kill -3 on
the process and then cat'ing a file descriptor, but i cannot recall
the exact sequence. Anyone recall?
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
George Niculae
2012-09-15 15:37:39 UTC
Permalink
You have to cat proc/fd pid while kill -3 to get something, check wiki

George
Post by Matt White
kill -3 <pid> does not work. I'm not sure if its because the process is
stuck but I can use on other java process but not the one stuck at 100%
Post by Matt White
Thats why i tried jack as its already available on the machine.
-m
kill -3 <pid>, optionally redirected to a file seems to work better than
jstack, though it will show the running threads, not how much CPU they use.
For that, you'd need to connect a profiler (e.g. VisualVM) to the running
process.
Post by Matt White
Alex
Try using
jmap -F -dump:file=dump.map PID
Loading in MemoryAnalyzerTool reveals issues
George
Post by Matt White
Yup.
But looking at the stack I dont think it really shows much. I see alot
A quick google would show jstack cant always walk the stack when its
hung, so I'm not sure its valid.
Post by Matt White
Post by Matt White
Its easy to replicate, copy over the jain-sip-sdp and restart call
control. Utilization goes to 100%.
Post by Matt White
Post by Matt White
Copy the old one back and restart call control and it goes back to normal.
When I have some spare time I might go back through some older releases
of jain-sip and see if the issue started at a specific release.
Post by Matt White
Post by Matt White
-M
this is when is was consuming 100% of CPU?
Post by Matt White
I used jstack to get a dump of the thread.
Contents available on pastebin: http://pastebin.com/qDSFC4HE
Post by Matt White
Just thought I'd give an update on updating the jain-sip
I've put this latest jain-sip in production on 3 system for several weeks
now. One 4.2.1 and the other 2 are 4.4
They are working fine and there is no useability issues. However the
sipxrest java process pegs at 100%.
Our systems are multi-core so it doesnt affect system usage.
Setting the call control logs to debug dont show any additional detail.
Is there a good way to debug the sipxrest process.
there was some way to dump the java thread and by calling kill -3 on
the process and then cat'ing a file descriptor, but i cannot recall
the exact sequence. Anyone recall?
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
_______________________________________________
sipx-users mailing list
M. Ranganathan
2012-09-14 12:32:42 UTC
Permalink
Please describe the sequence of events that leads to the 100% CPU situation.

When you say they are "working fine" does that imply your sipXbridge
issues are fine now?
Post by Matt White
Just thought I'd give an update on updating the jain-sip
I've put this latest jain-sip in production on 3 system for several weeks
now. One 4.2.1 and the other 2 are 4.4
They are working fine and there is no useability issues. However the
sipxrest java process pegs at 100%.
Our systems are multi-core so it doesnt affect system usage.
Setting the call control logs to debug dont show any additional detail.
Is there a good way to debug the sipxrest process.
-M
Matt White 08/13/12 12:14 PM >>>
Thanks, you just answered the questions in my last reply!
-M
Attached is a jar file for jain-sip. Replace the jar and tested it out
before posting traces please.
Don't be too nervous - you can always revert.
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
--
M. Ranganathan
Matt White
2012-09-14 13:00:53 UTC
Permalink
Yes, the latest jain-sip has fixed our issue with sipxbridge. We have tested this on 4.2.1 and 4.4

Here is the process we followed.
1. Shutdown sipx
2. Replace the current jain-sdp under the Sipxcommons and openfire directories with the new one.
3. startup sipx

As soon as sipx starts (and sipxrest by extension) there is one java process that will stay at 100%.
ps -ef indicated it was the sipxrest process.

If we restart the "call control" service in sipx via the webgui, the process will disappears for a second and then come back at 100%
If we kill the process from the cli then the process disappears and utilization drops, but then sipxsupervisor starts it back up and it stays at 100% again.

Here is the ps -ef output of the process, you can see it is loading the jain-sdp:

/usr/bin/java -Dcom.ibm.tools.attach.enable=no -Dconf.dir=/etc/sipxpbx -Dplugin.dir=/usr/share/java/sipXecs/sipXrest/plugins -Djav
ax.net.ssl.trustStore=/etc/sipxpbx/ssl/authorities.jks -Djavax.net.ssl.trustStoreType=JKS -Djavax.net.ssl.trustStorePassword=changeit -Djavax.net.ssl.keyStore=/etc/sipxpbx/ssl/ss
l.keystore -Djavax.net.ssl.keyStorePassword=changeit -Djetty.x509.algorithm=SunX509 -Djetty.ssl.password=changeit -Djetty.ssl.keypassword=changeit -Dorg.apache.commons.logging.Lo
g=org.apache.commons.logging.impl.Log4JLogger -Dsipxrest.command=start -cp /usr/share/java/sipXecs/sipXrest/sipxrest.jar:/usr/share/java/sipXecs/sipXcommons/Stun4J.jar:/usr/share
/java/sipXecs/sipXcommons/ant-launcher.jar:/usr/share/java/sipXecs/sipXcommons/ant.jar:/usr/share/java/sipXecs/sipXcommons/bcel.jar:/usr/share/java/sipXecs/sipXcommons/com.noelio
s.restlet.ext.servlet.jar:/usr/share/java/sipXecs/sipXcommons/com.noelios.restlet.jar:/usr/share/java/sipXecs/sipXcommons/commons-beanutils.jar:/usr/share/java/sipXecs/sipXcommon
s/commons-cli.jar:/usr/share/java/sipXecs/sipXcommons/commons-codec.jar:/usr/share/java/sipXecs/sipXcommons/commons-collections.jar:/usr/share/java/sipXecs/sipXcommons/commons-di
gester.jar:/usr/share/java/sipXecs/sipXcommons/commons-io.jar:/usr/share/java/sipXecs/sipXcommons/commons-lang.jar:/usr/share/java/sipXecs/sipXcommons/commons-logging-api.jar:/us
r/share/java/sipXecs/sipXcommons/commons-logging.jar:/usr/share/java/sipXecs/sipXcommons/commons-net.jar:/usr/share/java/sipXecs/sipXcommons/cpptasks.jar:/usr/share/java/sipXecs/
sipXcommons/dnsjava.jar:/usr/share/java/sipXecs/sipXcommons/dom4j.jar:/usr/share/java/sipXecs/sipXcommons/jain-sip-sdp.jar:/usr/share/java/sipXecs/sipXcommons/javamail.jar:/usr/s
hare/java/sipXecs/sipXcommons/javax.servlet.jar:/usr/share/java/sipXecs/sipXcommons/jaxen.jar:/usr/share/java/sipXecs/sipXcommons/jce.jar:/usr/share/java/sipXecs/sipXcommons/jdom
-1.0.jar:/usr/share/java/sipXecs/sipXcommons/jetty.jar:/usr/share/java/sipXecs/sipXcommons/jibx-bind.jar:/usr/share/java/sipXecs/sipXcommons/jibx-run.jar:/usr/share/java/sipXecs/
sipXcommons/junit.jar:/usr/share/java/sipXecs/sipXcommons/log4j.jar:/usr/share/java/sipXecs/sipXcommons/not-yet-commons-ssl.jar:/usr/share/java/sipXecs/sipXcommons/org.restlet.ja
r:/usr/share/java/sipXecs/sipXcommons/postgresql-jdbc.jar:/usr/share/java/sipXecs/sipXcommons/sipxcommons.jar:/usr/share/java/sipXecs/sipXcommons/smack.jar:/usr/share/java/sipXec
s/sipXcommons/smackx.jar:/usr/share/java/sipXecs/sipXcommons/ws-commons-util.jar:/usr/share/java/sipXecs/sipXcommons/xmlrpc-client.jar:/usr/share/java/sipXecs/sipXcommons/xmlrpc-
common.jar:/usr/share/java/sipXecs/sipXcommons/xmlrpc-server.jar:/usr/share/java/sipXecs/sipXcommons/xpp3.jar:/usr/share/java/sipXecs/sipXrest/plugins/sipXcallController.jar:/usr
/share/java/sipXecs/sipXrest/plugins/sipxcdrLog.jar org.sipfoundry.sipxrest.RestServer --start

-M
Please describe the sequence of events that leads to the 100% CPU situation.

When you say they are "working fine" does that imply your sipXbridge
issues are fine now?
Post by Matt White
Just thought I'd give an update on updating the jain-sip
I've put this latest jain-sip in production on 3 system for several weeks
now. One 4.2.1 and the other 2 are 4.4
They are working fine and there is no useability issues. However the
sipxrest java process pegs at 100%.
Our systems are multi-core so it doesnt affect system usage.
Setting the call control logs to debug dont show any additional detail.
Is there a good way to debug the sipxrest process.
-M
Matt White 08/13/12 12:14 PM >>>
Thanks, you just answered the questions in my last reply!
-M
Attached is a jar file for jain-sip. Replace the jar and tested it out
before posting traces please.
Don't be too nervous - you can always revert.
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
--
M. Ranganathan
M. Ranganathan
2012-09-14 13:08:06 UTC
Permalink
kill the process, tail a debut log of it. It will tell you more useful
information.
Post by Matt White
Yes, the latest jain-sip has fixed our issue with sipxbridge. We have
tested this on 4.2.1 and 4.4
Here is the process we followed.
1. Shutdown sipx
2. Replace the current jain-sdp under the Sipxcommons and openfire
directories with the new one.
3. startup sipx
As soon as sipx starts (and sipxrest by extension) there is one java process
that will stay at 100%.
ps -ef indicated it was the sipxrest process.
If we restart the "call control" service in sipx via the webgui, the process
will disappears for a second and then come back at 100%
If we kill the process from the cli then the process disappears and
utilization drops, but then sipxsupervisor starts it back up and it stays at
100% again.
/usr/bin/java -Dcom.ibm.tools.attach.enable=no -Dconf.dir=/etc/sipxpbx
-Dplugin.dir=/usr/share/java/sipXecs/sipXrest/plugins -Djav
ax.net.ssl.trustStore=/etc/sipxpbx/ssl/authorities.jks
-Djavax.net.ssl.trustStoreType=JKS
-Djavax.net.ssl.trustStorePassword=changeit
-Djavax.net.ssl.keyStore=/etc/sipxpbx/ssl/ss
l.keystore -Djavax.net.ssl.keyStorePassword=changeit
-Djetty.x509.algorithm=SunX509 -Djetty.ssl.password=changeit
-Djetty.ssl.keypassword=changeit -Dorg.apache.commons.logging.Lo
g=org.apache.commons.logging.impl.Log4JLogger -Dsipxrest.command=start -cp
/usr/share/java/sipXecs/sipXrest/sipxrest.jar:/usr/share/java/sipXecs/sipXcommons/Stun4J.jar:/usr/share
/java/sipXecs/sipXcommons/ant-launcher.jar:/usr/share/java/sipXecs/sipXcommons/ant.jar:/usr/share/java/sipXecs/sipXcommons/bcel.jar:/usr/share/java/sipXecs/sipXcommons/com.noelio
s.restlet.ext.servlet.jar:/usr/share/java/sipXecs/sipXcommons/com.noelios.restlet.jar:/usr/share/java/sipXecs/sipXcommons/commons-beanutils.jar:/usr/share/java/sipXecs/sipXcommon
s/commons-cli.jar:/usr/share/java/sipXecs/sipXcommons/commons-codec.jar:/usr/share/java/sipXecs/sipXcommons/commons-collections.jar:/usr/share/java/sipXecs/sipXcommons/commons-di
gester.jar:/usr/share/java/sipXecs/sipXcommons/commons-io.jar:/usr/share/java/sipXecs/sipXcommons/commons-lang.jar:/usr/share/java/sipXecs/sipXcommons/commons-logging-api.jar:/us
r/share/java/sipXecs/sipXcommons/commons-logging.jar:/usr/share/java/sipXecs/sipXcommons/commons-net.jar:/usr/share/java/sipXecs/sipXcommons/cpptasks.jar:/usr/share/java/sipXecs/
sipXcommons/dnsjava.jar:/usr/share/java/sipXecs/sipXcommons/dom4j.jar:/usr/share/java/sipXecs/sipXcommons/jain-sip-sdp.jar:/usr/share/java/sipXecs/sipXcommons/javamail.jar:/usr/s
hare/java/sipXecs/sipXcommons/javax.servlet.jar:/usr/share/java/sipXecs/sipXcommons/jaxen.jar:/usr/share/java/sipXecs/sipXcommons/jce.jar:/usr/share/java/sipXecs/sipXcommons/jdom
-1.0.jar:/usr/share/java/sipXecs/sipXcommons/jetty.jar:/usr/share/java/sipXecs/sipXcommons/jibx-bind.jar:/usr/share/java/sipXecs/sipXcommons/jibx-run.jar:/usr/share/java/sipXecs/
sipXcommons/junit.jar:/usr/share/java/sipXecs/sipXcommons/log4j.jar:/usr/share/java/sipXecs/sipXcommons/not-yet-commons-ssl.jar:/usr/share/java/sipXecs/sipXcommons/org.restlet.ja
r:/usr/share/java/sipXecs/sipXcommons/postgresql-jdbc.jar:/usr/share/java/sipXecs/sipXcommons/sipxcommons.jar:/usr/share/java/sipXecs/sipXcommons/smack.jar:/usr/share/java/sipXec
s/sipXcommons/smackx.jar:/usr/share/java/sipXecs/sipXcommons/ws-commons-util.jar:/usr/share/java/sipXecs/sipXcommons/xmlrpc-client.jar:/usr/share/java/sipXecs/sipXcommons/xmlrpc-
common.jar:/usr/share/java/sipXecs/sipXcommons/xmlrpc-server.jar:/usr/share/java/sipXecs/sipXcommons/xpp3.jar:/usr/share/java/sipXecs/sipXrest/plugins/sipXcallController.jar:/usr
/share/java/sipXecs/sipXrest/plugins/sipxcdrLog.jar
org.sipfoundry.sipxrest.RestServer --start
-M
Please describe the sequence of events that leads to the 100% CPU situation.
When you say they are "working fine" does that imply your sipXbridge
issues are fine now?
Post by Matt White
Just thought I'd give an update on updating the jain-sip
I've put this latest jain-sip in production on 3 system for several weeks
now. One 4.2.1 and the other 2 are 4.4
They are working fine and there is no useability issues. However the
sipxrest java process pegs at 100%.
Our systems are multi-core so it doesnt affect system usage.
Setting the call control logs to debug dont show any additional detail.
Is there a good way to debug the sipxrest process.
-M
Matt White 08/13/12 12:14 PM >>>
Thanks, you just answered the questions in my last reply!
-M
Attached is a jar file for jain-sip. Replace the jar and tested it out
before posting traces please.
Don't be too nervous - you can always revert.
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
--
M. Ranganathan
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
--
M. Ranganathan
Matt White
2012-09-14 13:27:01 UTC
Permalink
Yup, already have the sipxrest at debug. I was surprised but the lacl of activity in the log. With a clean log and starting the process after waiting about 5 minutes here all that has been recorded.

"2012-09-13T23:43:13.054000Z":1:JAVA:WARNING:voice:main:00000000:sipxrest:"using default tls security policy"
"2012-09-13T23:46:24.583000Z":1:JAVA:INFO:voice:main:00000000:StackLoggerImpl:"StackProperties {}{gov.nist.javax.sip.LOG_STACK_TRACE_ON_MESSAGE_SEND=false, gov.nist.javax.sip.IS_
BACK_TO_BACK_USER_AGENT=true, gov.nist.javax.sip.RFC_2543_SUPPORT_ENABLED=false, gov.nist.javax.sip.RECEIVE_UDP_BUFFER_SIZE=65536, gov.nist.javax.sip.MAX_FORK_TIME_SECONDS=180, g
ov.nist.javax.sip.TRACE_LEVEL=INFO, gov.nist.javax.sip.STACK_LOGGER=org.sipfoundry.commons.log4j.StackLoggerImpl, javax.sip.STACK_NAME=sipxrest, javax.sip.ROUTER_PATH=org.sipfoun
dry.commons.siprouter.ProxyRouter, gov.nist.javax.sip.REENTRANT_LISTENER=true, gov.nist.javax.sip.SERVER_LOGGER=org.sipfoundry.commons.log4j.ServerLoggerImpl, gov.nist.javax.sip.
THREAD_POOL_SIZE=1}"
"2012-09-13T23:46:24.585000Z":2:JAVA:INFO:voice:main:00000000:sipxrest:"value -1000 will be used for reliableConnectionKeepAliveTimeout stack property"
"2012-09-13T23:46:24.585000Z":3:JAVA:INFO:voice:main:00000000:sipxrest:"Setting Stack Thread priority to 10"
"2012-09-13T23:46:24.623000Z":4:JAVA:WARNING:voice:main:00000000:sipxrest:"using default tls security policy"
"2012-09-13T23:46:24.631000Z":5:JAVA:INFO:voice:main:00000000:sipxrest:"BuildTimeStamp = Date = 20120813 Time = 1138"
"2012-09-13T23:46:24.636000Z":6:JAVA:INFO:voice:main:00000000:sipxrest:"the sip stack timer gov.nist.javax.sip.stack.timers.DefaultSipTimer has been started"
"2012-09-13T23:48:10.051000Z":1:JAVA:INFO:voice:main:00000000:StackLoggerImpl:"StackProperties {}{gov.nist.javax.sip.LOG_STACK_TRACE_ON_MESSAGE_SEND=false, gov.nist.javax.sip.IS_
BACK_TO_BACK_USER_AGENT=true, gov.nist.javax.sip.RFC_2543_SUPPORT_ENABLED=false, gov.nist.javax.sip.RECEIVE_UDP_BUFFER_SIZE=65536, gov.nist.javax.sip.MAX_FORK_TIME_SECONDS=180, g
ov.nist.javax.sip.TRACE_LEVEL=INFO, gov.nist.javax.sip.STACK_LOGGER=org.sipfoundry.commons.log4j.StackLoggerImpl, javax.sip.STACK_NAME=sipxrest, javax.sip.ROUTER_PATH=org.sipfoun
dry.commons.siprouter.ProxyRouter, gov.nist.javax.sip.REENTRANT_LISTENER=true, gov.nist.javax.sip.SERVER_LOGGER=org.sipfoundry.commons.log4j.ServerLoggerImpl, gov.nist.javax.sip.
THREAD_POOL_SIZE=1}"

Perhaps setting the call control log to debug isnt actually getting set to debug.

I'll check it out.

-M
kill the process, tail a debut log of it. It will tell you more useful
information.
Post by Matt White
Yes, the latest jain-sip has fixed our issue with sipxbridge. We have
tested this on 4.2.1 and 4.4
Here is the process we followed.
1. Shutdown sipx
2. Replace the current jain-sdp under the Sipxcommons and openfire
directories with the new one.
3. startup sipx
As soon as sipx starts (and sipxrest by extension) there is one java process
that will stay at 100%.
ps -ef indicated it was the sipxrest process.
If we restart the "call control" service in sipx via the webgui, the process
will disappears for a second and then come back at 100%
If we kill the process from the cli then the process disappears and
utilization drops, but then sipxsupervisor starts it back up and it stays at
100% again.
/usr/bin/java -Dcom.ibm.tools.attach.enable=no -Dconf.dir=/etc/sipxpbx
-Dplugin.dir=/usr/share/java/sipXecs/sipXrest/plugins -Djav
ax.net.ssl.trustStore=/etc/sipxpbx/ssl/authorities.jks
-Djavax.net.ssl.trustStoreType=JKS
-Djavax.net.ssl.trustStorePassword=changeit
-Djavax.net.ssl.keyStore=/etc/sipxpbx/ssl/ss
l.keystore -Djavax.net.ssl.keyStorePassword=changeit
-Djetty.x509.algorithm=SunX509 -Djetty.ssl.password=changeit
-Djetty.ssl.keypassword=changeit -Dorg.apache.commons.logging.Lo
g=org.apache.commons.logging.impl.Log4JLogger -Dsipxrest.command=start -cp
/usr/share/java/sipXecs/sipXrest/sipxrest.jar:/usr/share/java/sipXecs/sipXcommons/Stun4J.jar:/usr/share
/java/sipXecs/sipXcommons/ant-launcher.jar:/usr/share/java/sipXecs/sipXcommons/ant.jar:/usr/share/java/sipXecs/sipXcommons/bcel.jar:/usr/share/java/sipXecs/sipXcommons/com.noelio
s.restlet.ext.servlet.jar:/usr/share/java/sipXecs/sipXcommons/com.noelios.restlet.jar:/usr/share/java/sipXecs/sipXcommons/commons-beanutils.jar:/usr/share/java/sipXecs/sipXcommon
s/commons-cli.jar:/usr/share/java/sipXecs/sipXcommons/commons-codec.jar:/usr/share/java/sipXecs/sipXcommons/commons-collections.jar:/usr/share/java/sipXecs/sipXcommons/commons-di
gester.jar:/usr/share/java/sipXecs/sipXcommons/commons-io.jar:/usr/share/java/sipXecs/sipXcommons/commons-lang.jar:/usr/share/java/sipXecs/sipXcommons/commons-logging-api.jar:/us
r/share/java/sipXecs/sipXcommons/commons-logging.jar:/usr/share/java/sipXecs/sipXcommons/commons-net.jar:/usr/share/java/sipXecs/sipXcommons/cpptasks.jar:/usr/share/java/sipXecs/
sipXcommons/dnsjava.jar:/usr/share/java/sipXecs/sipXcommons/dom4j.jar:/usr/share/java/sipXecs/sipXcommons/jain-sip-sdp.jar:/usr/share/java/sipXecs/sipXcommons/javamail.jar:/usr/s
hare/java/sipXecs/sipXcommons/javax.servlet.jar:/usr/share/java/sipXecs/sipXcommons/jaxen.jar:/usr/share/java/sipXecs/sipXcommons/jce.jar:/usr/share/java/sipXecs/sipXcommons/jdom
-1.0.jar:/usr/share/java/sipXecs/sipXcommons/jetty.jar:/usr/share/java/sipXecs/sipXcommons/jibx-bind.jar:/usr/share/java/sipXecs/sipXcommons/jibx-run.jar:/usr/share/java/sipXecs/
sipXcommons/junit.jar:/usr/share/java/sipXecs/sipXcommons/log4j.jar:/usr/share/java/sipXecs/sipXcommons/not-yet-commons-ssl.jar:/usr/share/java/sipXecs/sipXcommons/org.restlet.ja
r:/usr/share/java/sipXecs/sipXcommons/postgresql-jdbc.jar:/usr/share/java/sipXecs/sipXcommons/sipxcommons.jar:/usr/share/java/sipXecs/sipXcommons/smack.jar:/usr/share/java/sipXec
s/sipXcommons/smackx.jar:/usr/share/java/sipXecs/sipXcommons/ws-commons-util.jar:/usr/share/java/sipXecs/sipXcommons/xmlrpc-client.jar:/usr/share/java/sipXecs/sipXcommons/xmlrpc-
common.jar:/usr/share/java/sipXecs/sipXcommons/xmlrpc-server.jar:/usr/share/java/sipXecs/sipXcommons/xpp3.jar:/usr/share/java/sipXecs/sipXrest/plugins/sipXcallController.jar:/usr
/share/java/sipXecs/sipXrest/plugins/sipxcdrLog.jar
org.sipfoundry.sipxrest.RestServer --start
-M
Please describe the sequence of events that leads to the 100% CPU situation.
When you say they are "working fine" does that imply your sipXbridge
issues are fine now?
Post by Matt White
Just thought I'd give an update on updating the jain-sip
I've put this latest jain-sip in production on 3 system for several weeks
now. One 4.2.1 and the other 2 are 4.4
They are working fine and there is no useability issues. However the
sipxrest java process pegs at 100%.
Our systems are multi-core so it doesnt affect system usage.
Setting the call control logs to debug dont show any additional detail.
Is there a good way to debug the sipxrest process.
-M
Matt White 08/13/12 12:14 PM >>>
Thanks, you just answered the questions in my last reply!
-M
Attached is a jar file for jain-sip. Replace the jar and tested it out
before posting traces please.
Don't be too nervous - you can always revert.
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
--
M. Ranganathan
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
--
M. Ranganathan
Matt White
2012-09-17 18:01:40 UTC
Permalink
Thanks, thats the clue I needed. Here is the process i used to get the dump in case someone else is curious.

ls /proc/PID/fd/1

Output shows
/proc/PID/fd/1 -> pipe:[979841]

Doing a cat on /proc/PID/fd/1 while using kill -3 shows no output.

So then I use lsof to find that other process tied to the pipe.
lsof | grep 979841

This shows me the original thread and the Second PID used by sipxsupervisor.
ls /proc/Second PID/fd shows that pipe is tied to fd 39.

So know i can cat /proc/Second PID/fd/39

And I get a dump. I was also able to use jmap as suggested as well.

-M
I have yet to see an instance where kill -3 doesn't work. Check whether stdout isn't already redirected, that's where the output is printed.

Alex

On Sat, Sep 15, 2012 at 6:00 PM, Matt White <***@thesummit-grp.com> wrote:
kill -3 <pid> does not work. I'm not sure if its because the process is stuck but I can use on other java process but not the one stuck at 100%

Thats why i tried jack as its already available on the machine.

-m
kill -3 <pid>, optionally redirected to a file seems to work better than jstack, though it will show the running threads, not how much CPU they use. For that, you'd need to connect a profiler (e.g. VisualVM) to the running process.

Alex

On Fri, Sep 14, 2012 at 10:32 PM, George Niculae <***@ezuce.com> wrote:
Try using

jmap -F -dump:file=dump.map PID

Loading in MemoryAnalyzerTool reveals issues

George
Post by Matt White
Yup.
A quick google would show jstack cant always walk the stack when its hung, so I'm not sure its valid.
Its easy to replicate, copy over the jain-sip-sdp and restart call control. Utilization goes to 100%.
Copy the old one back and restart call control and it goes back to normal.
When I have some spare time I might go back through some older releases of jain-sip and see if the issue started at a specific release.
-M
this is when is was consuming 100% of CPU?
Post by Matt White
I used jstack to get a dump of the thread.
Contents available on pastebin: http://pastebin.com/qDSFC4HE
Post by Matt White
Just thought I'd give an update on updating the jain-sip
I've put this latest jain-sip in production on 3 system for several weeks
now. One 4.2.1 and the other 2 are 4.4
They are working fine and there is no useability issues. However the
sipxrest java process pegs at 100%.
Our systems are multi-core so it doesnt affect system usage.
Setting the call control logs to debug dont show any additional detail.
Is there a good way to debug the sipxrest process.
there was some way to dump the java thread and by calling kill -3 on
the process and then cat'ing a file descriptor, but i cannot recall
the exact sequence. Anyone recall?
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
_______________________________________________
sipx-users mailing list
sipx-***@list.sipfoundry.org
List Archive: http://list.sipfoundry.org/archive/sipx-users/







--
This email was Anti Virus checked by the Summit Technology Consulting Groups Astaro Security Gateway. http://www.astaro.com
Matt White
2012-09-17 18:07:16 UTC
Permalink
Output available here: http://pastebin.com/HB2p4TPR

jmap dump here: http://www.thesummit-grp.com/dump.map

-M
Thanks, thats the clue I needed. Here is the process i used to get the dump in case someone else is curious.

ls /proc/PID/fd/1

Output shows
/proc/PID/fd/1 -> pipe:[979841]

Doing a cat on /proc/PID/fd/1 while using kill -3 shows no output.

So then I use lsof to find that other process tied to the pipe.
lsof | grep 979841

This shows me the original thread and the Second PID used by sipxsupervisor.
ls /proc/Second PID/fd shows that pipe is tied to fd 39.

So know i can cat /proc/Second PID/fd/39

And I get a dump. I was also able to use jmap as suggested as well.

-M
I have yet to see an instance where kill -3 doesn't work. Check whether stdout isn't already redirected, that's where the output is printed.

Alex

On Sat, Sep 15, 2012 at 6:00 PM, Matt White <***@thesummit-grp.com> wrote:
kill -3 <pid> does not work. I'm not sure if its because the process is stuck but I can use on other java process but not the one stuck at 100%

Thats why i tried jack as its already available on the machine.

-m
kill -3 <pid>, optionally redirected to a file seems to work better than jstack, though it will show the running threads, not how much CPU they use. For that, you'd need to connect a profiler (e.g. VisualVM) to the running process.

Alex

On Fri, Sep 14, 2012 at 10:32 PM, George Niculae <***@ezuce.com> wrote:
Try using

jmap -F -dump:file=dump.map PID

Loading in MemoryAnalyzerTool reveals issues

George
Post by Matt White
Yup.
A quick google would show jstack cant always walk the stack when its hung, so I'm not sure its valid.
Its easy to replicate, copy over the jain-sip-sdp and restart call control. Utilization goes to 100%.
Copy the old one back and restart call control and it goes back to normal.
When I have some spare time I might go back through some older releases of jain-sip and see if the issue started at a specific release.
-M
this is when is was consuming 100% of CPU?
Post by Matt White
I used jstack to get a dump of the thread.
Contents available on pastebin: http://pastebin.com/qDSFC4HE
Post by Matt White
Just thought I'd give an update on updating the jain-sip
I've put this latest jain-sip in production on 3 system for several weeks
now. One 4.2.1 and the other 2 are 4.4
They are working fine and there is no useability issues. However the
sipxrest java process pegs at 100%.
Our systems are multi-core so it doesnt affect system usage.
Setting the call control logs to debug dont show any additional detail.
Is there a good way to debug the sipxrest process.
there was some way to dump the java thread and by calling kill -3 on
the process and then cat'ing a file descriptor, but i cannot recall
the exact sequence. Anyone recall?
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
_______________________________________________
sipx-users mailing list
sipx-***@list.sipfoundry.org
List Archive: http://list.sipfoundry.org/archive/sipx-users/







--
This email was Anti Virus checked by the Summit Technology Consulting Groups Astaro Security Gateway. http://www.astaro.com
Matt White
2012-09-17 20:28:21 UTC
Permalink
Utilization issue appears to be jain-sip build specific.

I back rev'd the jain-sip-sdp-1.2.2140.jar to jain-sip-sdp-1.2.2014.jar and CPU utilization has gone away.

I will resume testing to see how well this version of jain-sip functions with sipxbridge. 1.2.2014 is still way newer than what is shipped with sipx.

-M
Post by Matt White
Post by Matt White
Matt White 09/17/12 2:07 PM >>>
Output available here: http://pastebin.com/HB2p4TPR

jmap dump here: http://www.thesummit-grp.com/dump.map

-M
Thanks, thats the clue I needed. Here is the process i used to get the dump in case someone else is curious.

ls /proc/PID/fd/1

Output shows
/proc/PID/fd/1 -> pipe:[979841]

Doing a cat on /proc/PID/fd/1 while using kill -3 shows no output.

So then I use lsof to find that other process tied to the pipe.
lsof | grep 979841

This shows me the original thread and the Second PID used by sipxsupervisor.
ls /proc/Second PID/fd shows that pipe is tied to fd 39.

So know i can cat /proc/Second PID/fd/39

And I get a dump. I was also able to use jmap as suggested as well.

-M
I have yet to see an instance where kill -3 doesn't work. Check whether stdout isn't already redirected, that's where the output is printed.

Alex

On Sat, Sep 15, 2012 at 6:00 PM, Matt White <***@thesummit-grp.com> wrote:
kill -3 <pid> does not work. I'm not sure if its because the process is stuck but I can use on other java process but not the one stuck at 100%

Thats why i tried jack as its already available on the machine.

-m
kill -3 <pid>, optionally redirected to a file seems to work better than jstack, though it will show the running threads, not how much CPU they use. For that, you'd need to connect a profiler (e.g. VisualVM) to the running process.

Alex

On Fri, Sep 14, 2012 at 10:32 PM, George Niculae <***@ezuce.com> wrote:
Try using

jmap -F -dump:file=dump.map PID

Loading in MemoryAnalyzerTool reveals issues

George
Post by Matt White
Yup.
A quick google would show jstack cant always walk the stack when its hung, so I'm not sure its valid.
Its easy to replicate, copy over the jain-sip-sdp and restart call control. Utilization goes to 100%.
Copy the old one back and restart call control and it goes back to normal.
When I have some spare time I might go back through some older releases of jain-sip and see if the issue started at a specific release.
-M
this is when is was consuming 100% of CPU?
Post by Matt White
I used jstack to get a dump of the thread.
Contents available on pastebin: http://pastebin.com/qDSFC4HE
Just thought I'd give an update on updating the jain-sip
I've put this latest jain-sip in production on 3 system for several weeks
now. One 4.2.1 and the other 2 are 4.4
They are working fine and there is no useability issues. However the
sipxrest java process pegs at 100%.
Our systems are multi-core so it doesnt affect system usage.
Setting the call control logs to debug dont show any additional detail.
Is there a good way to debug the sipxrest process.
there was some way to dump the java thread and by calling kill -3 on
the process and then cat'ing a file descriptor, but i cannot recall
the exact sequence. Anyone recall?
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
_______________________________________________
sipx-users mailing list
List Archive: http://list.sipfoundry.org/archive/sipx-users/
_______________________________________________
sipx-users mailing list
sipx-***@list.sipfoundry.org
List Archive: http://list.sipfoundry.org/archive/sipx-users/







--
This email was Anti Virus checked by the Summit Technology Consulting Groups Astaro Security Gateway. http://www.astaro.com
Loading...