Re: Java process segfaulting and using 100% CPU

2006-04-27 Thread Gustavo Noronha
2006/4/20, Gustavo Noronha [EMAIL PROTECTED]:


 Like I said in a previous email, I know about dumping thread information,
 but I am unnable to identify what thread is using up the CPU cycles. What I
 did to try to fix this problem is setting up some different c3p0
 configurations:

 on hibernate.properties:

 hibernate.c3p0.idle_test_period=200
 hibernate.c3p0.acquire_increment=3

 on c3p0.properties (newly created):

 c3p0.numHelperThreads 8

 I haven't seen c3p0 problems up to now, nor 100%-cpu-using processes
 simply segfaulting and futexing, but it's still early to decide whether it
 fixed the problem or not. I'd still like to have insights on where the
 problem may lie. I am afraid to be work-arounding the problem with a c3p0
 configuration when in fact the application is misbehaving with the
 connections, for instance.



So, just to let you know, after this configuration was done I haven't seen
the problems I mentioned yet. The one other thing I did was increasing the
maximum size of the jvm heap, after seing an OutOfMemory error, but these
errors only happened once, and do not seem to be related to the other
problem. The system was running fine days before I did that change, too.

Thanks for all the help!

--
Gustavo Noronha Silva
Coordenação de Segurança e Sustentação
Ministério do Desenvolvimento Social - Brasil


Re: Java process segfaulting and using 100% CPU

2006-04-21 Thread Leon Rosenberg
I don't know it depends on your implementation of hashCode() method.
Are you using 1.5?

static int hash(Object x) {
int h = x.hashCode(); -- your programm is here

h += ~(h  9);
h ^=  (h  14);
h +=  (h  4);
h ^=  (h  10);
return h;
}

I think chances are low that the you see threads in this method often.
Would you mind checking the hashCode() method implementation of the
objects you put in the map?

Maybe someone programmed some kind of very-cool-hash-code-optimization
and got an infinite loop.

regards
Leon

On 4/20/06, Gustavo Noronha [EMAIL PROTECTED] wrote:
 2006/4/20, Leon Rosenberg [EMAIL PROTECTED]:
 
  do you see those often?


 The developers tell me that this is part of a process that generates an XML
 file that goes in a new clob column of the database. They are running a
 batch process during the night that is generating the XML for each of the
 already existing records, and some XMLs are being generated during the day
 while users complete filling the data they need to fill in.

 Does it look faulty?

 Right now I have some processes using 100% cpu and the only reference to
 HashMap I have is this:

 http-8080-Processor19 daemon prio=1 tid=0x088b5120 nid=0x5b5d runnable
 [0x6c506000..0x6c5086c0]
 at java.util.HashMap.hash(HashMap.java:264)
 at java.util.HashMap.get(HashMap.java:320)
 at org.apache.commons.collections.SequencedHashMap.get(Unknown
 Source)
 at org.hibernate.util.IdentityMap.get(IdentityMap.java:132)
 at org.hibernate.engine.PersistenceContext.getEntry(
 PersistenceContext.java:373)
 at org.hibernate.type.CollectionType.getKeyOfOwner(
 CollectionType.java:289)
 at org.hibernate.engine.Collections.processReachableCollection(
 Collections.java:137)
 at org.hibernate.event.def.FlushVisitor.processCollection(
 FlushVisitor.java:37)

 Thanks,

 --
 Gustavo Noronha Silva
 Coordenação de Segurança e Sustentação
 Ministério do Desenvolvimento Social - Brasil


-
To unsubscribe, e-mail: [EMAIL PROTECTED]
For additional commands, e-mail: [EMAIL PROTECTED]



Re: Java process segfaulting and using 100% CPU

2006-04-21 Thread David Delbecq
There are several ways to find out where tomcat is spending all it's cpu
time
1) when it's a 100% CPU eating time issue a few stacktraces at a 10 or
20 seconds interval. then compare all those trace and try to find a
stacktrace which is recurrent. This is clearly not easy and might
require quite a few hours of analysis to point a list of reccurrent
working area during the various dumps. If you have an endless loop of a
very slow process, it should be present in a thread for all dumps.
2) check twice you don't have memory consumption problems. We noticed a
few time here that tomcat behaving very slowly is a prefail warning of a
memory outtage (The garbage collector becomes aggressive). So increase
max memory and max permergensize. (You should get out of memory errors
anyway in the end if this is the case
3) Use a profiling tool to get reports on CPU usage by various areas of
code. When it comes to debugging CPU usage or memory leaks, profilers
are very usefull. The drawback is you have to run your tomcat in a
profiled environnment which will take note of execution time of all your
method calls. If you can't reproduce your problem on a test server ,that
mean you need to profile your production server, but profiling tomcat
render it about 4 to 10 times slower, depending on the profiler, the
memory on server, etc.


2 points in stack trace worth checking, i noticed 2 threads are not in
sleep state and have a similar part in stack trace, check twice if there
is no endless loop around

at br.gov.mds.suasnob.data.pessoafisica.PessoaFisicaData.getPapelList(
PessoaFisicaData.java:185)
at br.gov.mds.suasnob.data.pessoafisica.PessoaFisicaData.getPapeis(
PessoaFisicaData.java:160)


partial traces:

http-8080-Processor7 daemon prio=1 tid=0x08b6c9f8 nid=0x5048 runnable
[0x6f627000..0x6f6296c0]
at org.hibernate.event.def.AbstractVisitor.processValue(
AbstractVisitor.java:102)
at org.hibernate.event.def.AbstractVisitor.processValue(
AbstractVisitor.java:64)
at org.hibernate.event.def.AbstractVisitor.processEntityPropertyValues(
AbstractVisitor.java:58)
at org.hibernate.event.def.DefaultFlushEntityEventListener.onFlushEntity
(DefaultFlushEntityEventListener.java:198)
at org.hibernate.event.def.AbstractFlushingEventListener.flushEntities(
AbstractFlushingEventListener.java:190)
at
org.hibernate.event.def.AbstractFlushingEventListener.flushEverythingToExecutions
(AbstractFlushingEventListener.java:70)
at org.hibernate.event.def.DefaultAutoFlushEventListener.onAutoFlush(
DefaultAutoFlushEventListener.java:39)
at org.hibernate.impl.SessionImpl.autoFlushIfRequired(SessionImpl.java
:711)
at org.hibernate.impl.SessionImpl.prepareQueries(SessionImpl.java:895)
at org.hibernate.impl.SessionImpl.getQueries(SessionImpl.java:885)
at org.hibernate.impl.SessionImpl.list(SessionImpl.java:834)
at org.hibernate.impl.QueryImpl.list(QueryImpl.java:74)
at br.gov.mds.suasnob.data.pessoafisica.PessoaFisicaData.getPapelList(
PessoaFisicaData.java:185)
at br.gov.mds.suasnob.data.pessoafisica.PessoaFisicaData.getPapeis(
PessoaFisicaData.java:160)



at org.hibernate.engine.ActionQueue.sortCollectionActions(
ActionQueue.java:292)
at
org.hibernate.event.def.AbstractFlushingEventListener.flushCollections(
AbstractFlushingEventListener.java:244)
at
org.hibernate.event.def.AbstractFlushingEventListener.flushEverythingToExecutions
(AbstractFlushingEventListener.java:71)
at org.hibernate.event.def.DefaultAutoFlushEventListener.onAutoFlush(
DefaultAutoFlushEventListener.java:39)
at org.hibernate.impl.SessionImpl.autoFlushIfRequired(SessionImpl.java
:711)
at org.hibernate.impl.SessionImpl.prepareQueries(SessionImpl.java:895)
at org.hibernate.impl.SessionImpl.getQueries(SessionImpl.java:885)
at org.hibernate.impl.SessionImpl.list(SessionImpl.java:834)
at org.hibernate.impl.QueryImpl.list(QueryImpl.java:74)
at br.gov.mds.suasnob.data.pessoafisica.PessoaFisicaData.getPapelList(
PessoaFisicaData.java:185)
at br.gov.mds.suasnob.data.pessoafisica.PessoaFisicaData.getPapeis(
PessoaFisicaData.java:160)
at sun.reflect.GeneratedMethodAccessor1697.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(
DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at ognl.OgnlRuntime.invokeMethod(OgnlRuntime.java:491)
at ognl.OgnlRuntime.callAppropriateMethod(OgnlRuntime.java:785)
at ognl.ObjectMethodAccessor.callMethod(ObjectMethodAccessor.java:61)

..

Gustavo Noronha a écrit :

Hey David!

2006/4/20, David Delbecq [EMAIL PROTECTED]:
  

the kill -3 send a signal, that is you must send it to a process (in you
case the java virtual machine). The sun java machine has the behaviour
to dump a full stacktrace of all it's threads when it receive this. Of
course you won't get the dump in the console where you ran kill it. it
will probably be in catalina.out




Sure; but do you 

Re: Java process segfaulting and using 100% CPU

2006-04-21 Thread David Delbecq
Leon Rosenberg a écrit :

I don't know it depends on your implementation of hashCode() method.
Are you using 1.5?

static int hash(Object x) {
int h = x.hashCode(); -- your programm is here

h += ~(h  9);
h ^=  (h  14);
h +=  (h  4);
h ^=  (h  10);
return h;
}

I think chances are low that the you see threads in this method often.
Would you mind checking the hashCode() method implementation of the
objects you put in the map?

Maybe someone programmed some kind of very-cool-hash-code-optimization
and got an infinite loop.
  

  

False :)

Please note the thread dumps tells the Thread http-8080-Processor56 is in

java.util.HashMap.hash(HashMap.java:264)
not in something like com.company.veryCoolClass.hashCode();

as you said, the program is here : int h = x.hashCode()
that mean it is either in the step of putting the value from registers to h , 
either in precall of x.hashCode(). In no way is it currently running 
x.hashCode() :)
Please also note, chance to get Threads in there are not so low when you play a 
lots with Hashmap :)



-
To unsubscribe, e-mail: [EMAIL PROTECTED]
For additional commands, e-mail: [EMAIL PROTECTED]



Re: Java process segfaulting and using 100% CPU

2006-04-20 Thread Gustavo Noronha
2006/4/20, opensta [EMAIL PROTECTED]:


 Just Type kill -QUIT pid-of-process command you will get the thread dump
 in
 catalina.out file of tomcat log folder

 u can identify the ur thread which are culprit from that


Like I said in a previous email, I know about dumping thread information,
but I am unnable to identify what thread is using up the CPU cycles. What I
did to try to fix this problem is setting up some different c3p0
configurations:

on hibernate.properties:

hibernate.c3p0.idle_test_period=200
hibernate.c3p0.acquire_increment=3

on c3p0.properties (newly created):

c3p0.numHelperThreads 8

I haven't seen c3p0 problems up to now, nor 100%-cpu-using processes simply
segfaulting and futexing, but it's still early to decide whether it fixed
the problem or not. I'd still like to have insights on where the problem may
lie. I am afraid to be work-arounding the problem with a c3p0 configuration
when in fact the application is misbehaving with the connections, for
instance.

Thanks,

--
Gustavo Noronha Silva
Coordenação de Segurança e Sustentação
Ministério do Desenvolvimento Social - Brasil


Re: Java process segfaulting and using 100% CPU

2006-04-20 Thread Leon Rosenberg
could you attach the thread dump?
Leon

On 4/20/06, Gustavo Noronha [EMAIL PROTECTED] wrote:
 2006/4/20, opensta [EMAIL PROTECTED]:
 
 
  Just Type kill -QUIT pid-of-process command you will get the thread dump
  in
  catalina.out file of tomcat log folder
 
  u can identify the ur thread which are culprit from that


 Like I said in a previous email, I know about dumping thread information,
 but I am unnable to identify what thread is using up the CPU cycles. What I
 did to try to fix this problem is setting up some different c3p0
 configurations:

 on hibernate.properties:

 hibernate.c3p0.idle_test_period=200
 hibernate.c3p0.acquire_increment=3

 on c3p0.properties (newly created):

 c3p0.numHelperThreads 8

 I haven't seen c3p0 problems up to now, nor 100%-cpu-using processes simply
 segfaulting and futexing, but it's still early to decide whether it fixed
 the problem or not. I'd still like to have insights on where the problem may
 lie. I am afraid to be work-arounding the problem with a c3p0 configuration
 when in fact the application is misbehaving with the connections, for
 instance.

 Thanks,

 --
 Gustavo Noronha Silva
 Coordenação de Segurança e Sustentação
 Ministério do Desenvolvimento Social - Brasil


-
To unsubscribe, e-mail: [EMAIL PROTECTED]
For additional commands, e-mail: [EMAIL PROTECTED]



Re: Java process segfaulting and using 100% CPU

2006-04-20 Thread Leon Rosenberg
do you see those often?
Leon


http-8080-Processor56 daemon prio=1 tid=0x0834f0a8 nid=0x598c runnable
[0x7059d000..0x7059e5c0]
   at java.util.HashMap.hash(HashMap.java:264)
   at java.util.HashMap.get(HashMap.java:320)
   at java.util.Collections$SynchronizedMap.get(Collections.java:1979)
   - locked 0x66200208 (a java.util.Collections$SynchronizedMap)
   at
com.thoughtworks.xstream.converters.reflection.SerializationMethodInvoker.getMethod
(SerializationMethodInvoker.java:99)
   at
com.thoughtworks.xstream.converters.reflection.SerializationMethodInvoker.callReadResolve
(SerializationMethodInvoker.java:31)
   at
com.thoughtworks.xstream.converters.reflection.ReflectionConverter.unmarshal
(ReflectionConverter.java:115)
   at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(
TreeUnmarshaller.java:38)
   at
com.thoughtworks.xstream.core.ReferenceByXPathUnmarshaller.convertAnother(
ReferenceByXPathUnmarshaller.java:39)
   at

-
To unsubscribe, e-mail: [EMAIL PROTECTED]
For additional commands, e-mail: [EMAIL PROTECTED]



Re: Java process segfaulting and using 100% CPU

2006-04-20 Thread David Delbecq
Gustavo Noronha a écrit :


Any hints on how to associate a thread with an OS PID? Or any other way of
identifying what thread is the culprit? I have played with the kill -3
feature, but didn't get very far investigating the output. =(

Thanks!

  

the kill -3 send a signal, that is you must send it to a process (in you
case the java virtual machine). The sun java machine has the behaviour
to dump a full stacktrace of all it's threads when it receive this. Of
course you won't get the dump in the console where you ran kill it. it
will probably be in catalina.out

Shoud look like this

Full thread dump Java HotSpot(TM) Client VM (1.4.2_05-b04 mixed mode):

Store be.rmi.intranet.slide.JNDIPrincipalStore Expiry Thread daemon
prio=1 tid=0x0864ba68 nid=0x765d waiting on condition [a8d37000..a8d3723c]
at java.lang.Thread.sleep(Native Method)
at
net.sf.ehcache.store.DiskStore.expiryThreadMain(DiskStore.java:641)
at net.sf.ehcache.store.DiskStore.access$700(DiskStore.java:89)
at
net.sf.ehcache.store.DiskStore$ExpiryThread.run(DiskStore.java:772)

Store be.rmi.intranet.slide.JNDIPrincipalStore Spool Thread daemon
prio=1 tid=0x08625be8 nid=0x765d in Object.wait() [a8db8000..a8db823c]
at java.lang.Object.wait(Native Method)
- waiting on 0xac4b2178 (a net.sf.ehcache.store.DiskStore)
at java.lang.Object.wait(Object.java:429)
at
net.sf.ehcache.store.DiskStore.spoolThreadMain(DiskStore.java:476)
- locked 0xac4b2178 (a net.sf.ehcache.store.DiskStore)
at net.sf.ehcache.store.DiskStore.access$600(DiskStore.java:89)
at
net.sf.ehcache.store.DiskStore$SpoolThread.run(DiskStore.java:755)

Signal Dispatcher daemon prio=1 tid=0x080a7150 nid=0x765d runnable [0..0]

Finalizer daemon prio=1 tid=0x080a2780 nid=0x765d in Object.wait()
[ab24d000..ab24d23c]
at java.lang.Object.wait(Native Method)
- waiting on 0xab8bb448 (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:111)
- locked 0xab8bb448 (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=1 tid=0x080a1b90 nid=0x765d in
Object.wait() [ab2ce000..ab2ce23c]
at java.lang.Object.wait(Native Method)
- waiting on 0xab8bb4b0 (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 0xab8bb4b0 (a java.lang.ref.Reference$Lock)

main prio=1 tid=0x0805bfb8 nid=0x765d runnable [bfc08000..bfc09558]
at
oracle.jdbc.driver.OraclePreparedStatement.clinit(OraclePreparedStatement.java:92)
at
oracle.jdbc.driver.T4CDriverExtension.allocatePreparedStatement(T4CDriverExtension.java:70)
at
oracle.jdbc.driver.PhysicalConnection.prepareStatement(PhysicalConnection.java:853)
- locked 0xac57c6b0 (a oracle.jdbc.driver.T4CConnection)
at
oracle.jdbc.driver.PhysicalConnection.prepareStatement(PhysicalConnection.java:759)
- locked 0xac57c6b0 (a oracle.jdbc.driver.T4CConnection)
at
org.apache.commons.dbcp.DelegatingConnection.prepareStatement(DelegatingConnection.java:185)
at
org.apache.commons.dbcp.PoolingDriver$PoolGuardConnectionWrapper.prepareStatement(PoolingDriver.java:338)
at
org.apache.slide.store.impl.rdbms.StandardRDBMSAdapter.assureUriId(StandardRDBMSAdapter.java:1266)
at
org.apache.slide.store.impl.rdbms.StandardRDBMSAdapter.storeObject(StandardRDBMSAdapter.java:101)
at
org.apache.slide.store.impl.rdbms.StandardRDBMSAdapter.createObject(StandardRDBMSAdapter.java:83)
at
org.apache.slide.store.impl.rdbms.AbstractRDBMSStore.createObject(AbstractRDBMSStore.java:443)
at
org.apache.slide.store.AbstractStore.createObject(AbstractStore.java:670)
at
org.apache.slide.store.ExtendedStore.createObject(ExtendedStore.java:602)
at
org.apache.slide.common.Namespace.loadBaseData(Namespace.java:785)
at org.apache.slide.common.Domain.initNamespace(Domain.java:845)
at org.apache.slide.common.Domain.init(Domain.java:432)
at org.apache.slide.common.Domain.init(Domain.java:366)
at org.apache.slide.common.Domain.init(Domain.java:329)
at
be.rmi.intranet.servlet.SetupServlet.initSubSystems(SetupServlet.java:152)
at be.rmi.intranet.servlet.SetupServlet.init(SetupServlet.java:139)
at javax.servlet.GenericServlet.init(GenericServlet.java:211)
at be.rmi.intranet.servlet.SetupServlet.init(SetupServlet.java:142)
at
org.apache.catalina.core.StandardWrapper.loadServlet(StandardWrapper.java:1068)
- locked 0xac2ca0e8 (a org.apache.catalina.core.StandardWrapper)
at
org.apache.catalina.core.StandardWrapper.load(StandardWrapper.java:900)
- locked 0xac2ca0e8 (a 

Re: Java process segfaulting and using 100% CPU

2006-04-20 Thread Gustavo Noronha
2006/4/20, Leon Rosenberg [EMAIL PROTECTED]:

 do you see those often?


The developers tell me that this is part of a process that generates an XML
file that goes in a new clob column of the database. They are running a
batch process during the night that is generating the XML for each of the
already existing records, and some XMLs are being generated during the day
while users complete filling the data they need to fill in.

Does it look faulty?

Right now I have some processes using 100% cpu and the only reference to
HashMap I have is this:

http-8080-Processor19 daemon prio=1 tid=0x088b5120 nid=0x5b5d runnable
[0x6c506000..0x6c5086c0]
at java.util.HashMap.hash(HashMap.java:264)
at java.util.HashMap.get(HashMap.java:320)
at org.apache.commons.collections.SequencedHashMap.get(Unknown
Source)
at org.hibernate.util.IdentityMap.get(IdentityMap.java:132)
at org.hibernate.engine.PersistenceContext.getEntry(
PersistenceContext.java:373)
at org.hibernate.type.CollectionType.getKeyOfOwner(
CollectionType.java:289)
at org.hibernate.engine.Collections.processReachableCollection(
Collections.java:137)
at org.hibernate.event.def.FlushVisitor.processCollection(
FlushVisitor.java:37)

Thanks,

--
Gustavo Noronha Silva
Coordenação de Segurança e Sustentação
Ministério do Desenvolvimento Social - Brasil


Re: Java process segfaulting and using 100% CPU

2006-04-20 Thread Gustavo Noronha
Hey David!

2006/4/20, David Delbecq [EMAIL PROTECTED]:

 the kill -3 send a signal, that is you must send it to a process (in you
 case the java virtual machine). The sun java machine has the behaviour
 to dump a full stacktrace of all it's threads when it receive this. Of
 course you won't get the dump in the console where you ran kill it. it
 will probably be in catalina.out


Sure; but do you know a way of relating one of the dumped threads with the
PID given by top, so I can figure out what thread is eating CPU?

Thanks,

--
Gustavo Noronha Silva
Coordenação de Segurança e Sustentação
Ministério do Desenvolvimento Social - Brasil


Java process segfaulting and using 100% CPU

2006-04-19 Thread Gustavo Noronha
Hello,

I've searched a lot about this issue on the web, but did not find a
solution. I have the following setup:

Debian GNU/Linux 3.1 with official Tomcat5 package (5.0.30),
java-package-built Sun JVM:

# java -version
java version 1.5.0_05
Java(TM) 2 Runtime Environment, Standard Edition (build 1.5.0_05-b05)
Java HotSpot(TM) Server VM (build 1.5.0_05-b05, mixed mode)

Our main application uses Hibernate to persist objects and C3P0 to control
the connection pool. Here's the configuration file:

hibernate.connection.driver_class com.p6spy.engine.spy.P6SpyDriver
hibernate.connection.url jdbc:oracle:thin:@dbhost:1521:sid
hibernate.connection.username user
hibernate.connection.password pass
hibernate.transaction.factory_class =
org.hibernate.transaction.JDBCTransactionFactory
hibernate.use_outer_join true
hibernate.show_sql false
hibernate.c3p0.minPoolSize = 10
hibernate.c3p0.maxPoolSize = 200;
hibernate.c3p0.min_size=10
hibernate.c3p0.max_size=200
hibernate.c3p0.timeout=5000
hibernate.c3p0.max_statements=0
hibernate.cglib.use_reflection_optimizer=true
hibernate.dialect org.hibernate.dialect.OracleDialect

I use the P6SpyDriver to be able to log the SQL queries that go through to
the Oracle database, but I have the same problem with the OracleDriver as
well. So here's the problem:

After some time running one java process begins using 100% CPU; strace shows
this:

--- SIGSEGV (Segmentation fault) @ 0 (0) ---
rt_sigreturn(0x55d32bda)= -442421359
futex(0x805c770, FUTEX_WAIT, 2, NULL)   = -1 EAGAIN (Resource temporarily
unavailable)
futex(0x81ff918, FUTEX_REQUEUE, 1, 2147483647, 0x805c770) = 1
futex(0x805c770, FUTEX_WAKE, 1) = 1
futex(0x805c7f0, FUTEX_WAIT, 2, NULL)   = 0
futex(0x805c7f0, FUTEX_WAKE, 1) = 0
--- SIGSEGV (Segmentation fault) @ 0 (0) ---
rt_sigreturn(0x500ddbda)= -442421359
futex(0x805c770, FUTEX_WAIT, 2, NULL)   = 0
futex(0x81ff918, FUTEX_REQUEUE, 1, 2147483647, 0x805c770) = 1
futex(0x805c770, FUTEX_WAKE, 1) = 1
futex(0x805c7f0, FUTEX_WAIT, 2, NULL)   = 0
futex(0x805c7f0, FUTEX_WAKE, 1) = 0

This may stay like that for the whole day, tomcat being responsive, or other
processes may end up using 100% CPU as well and presenting the same behavior
while on strace. Eventually, tomcat may become unresponsive, but I could not
estabilish a pattern. I found similar SIGSEGV/futex behavior on a
non-100%-using process, too:

send(23,
\2c\0\0\6\0\0\0\0\0\21i\0\1\1\1\1\1\3^\0\2\200!\0\1\2\2\\1\1\r\0\0\0\0\4\177\377\377\377\0\0\0\0\0\0\0\0\0select
papelpesso0_.ID_ENTIDADE_DIRIGENTE as ID1_, papelpesso0_.DT_INICIO_MANDATO
as DT2_29_, papelpesso0_.DT_FIM_MANDATO as DT3_29_,
papelpesso0_.DT_NOMEACAO_DIRIGENTE as DT4_29_, papelpesso0_.NU_REMESSA_SIAFI
as NU5_29_, papelpesso0_.DT_ENVIO_CREDOR_SIAFI as DT6_29_,
papelpesso0_.DT_RETORNO_CREDOR_SIAFI as DT7_29_, papelpesso0_.ST_RESPONSAVEL
as ST8_29_, papelpesso0_.CO_ENTIDADE as CO9_29_, papelpesso0_.CO_DIRIGENTE
as CO10_29_, papelpesso0_.CO_CARGO as CO11_29_ from RL_ENTIDADE_DIRIGENTE
papelpesso0_ where
papelpesso0_.CO_DIRIGENTE=28071\1\1\0\0\0\0\0\0\1\1\0\0\0\0\0, 611, 0) =
611
recv(23, \1\217\0\0\6\0\0\0, 8, 0)= 8
recv(23, \0\0\20\31\0279
\273t6X\203\0\0xj\4\22\27\0220\4\31\0\0\0\0\0\0\1\201\1\v7\2\0\t\0\1\26\0\0\0\0\0\0\0\0\4\1\4\4ID1_\0\0\f\0\0\0\1\1\0\0\0\0\0\0\0\1\7\1\7\7DT2_29_\0\0\f\0\0\0\1\1\0\0\0\0\0\0\0\1\7\1\7\7DT3_29_\0\0\f\0\0\0\1\1\0\0\0\0\0\0\0\1\7\1\7\7DT4_29_\0\0\1\200\0\0\1\5\0\0\0\0\1\37\1\1\5\1\7\1\7\7NU5_29_\0\0\f\0\0\0\1\1\0\0\0\0\0\0\0\1\7\1\7\7DT6_29_\0\0\f\0\0\0\1\1\0\0\0\0\0\0\0\1\7\1\7\7DT7_29_\0\0`\200\0\0\1\1\0\0\0\0\1\37\1\1\1\1\7\1\7\7ST8_29_\0\0\2\0\f\0\1\26\0\0\0\0\0\0\0\0\7\1\7\7CO9_29_\0\0\2\0\n\0\1\26\0\0\0\0\0\0\0\0\10\1\10\10CO10_29_\0\0\2\0\t\0\1\26\0\0\0\0\0\0\0\0\10\1\10\10CO11_29_\0\0\1\7\7xj\4\23\2!\17\10\1\5\3+\367Y\0\1\1\0\0\0\0\4\0\0\0\0\1\1\2\1\332\3\0\0\0\0\0\2\177|\1\1\0\2\317/\1\5\0\0\0\0\1\1,
391, 0) = 391
send(23, \0\21\0\0\6\0\0\0\0\0\3\5\0\1\1\1\n, 17, 0) = 17
recv(23, \0F\0\0\6\0\0\0, 8, 0)   = 8
recv(23, \0\0\4\0\2\5{\0\0\1\1\0\3\0\1
\0\0\0\2\177|\1\1\0\2\317/\1\5\0\0\0\0\1\1\31ORA-01403: no data found\n,
62, 0) = 62
gettimeofday({1145421443, 130050}, NULL) = 0
gettimeofday({1145421443, 130213}, NULL) = 0
write(14, 1145421443130|17|37|statement|select
papelpesso0_.ID_ENTIDADE_DIRIGENTE as ID1_, papelpesso0_.DT_INICIO_MANDATO
as DT2_29_, papelpesso0_.DT_FIM_MANDATO as DT3_29_,
papelpesso0_.DT_NOMEACAO_DIRIGENTE as DT4_29_, papelpesso0_.NU_REMESSA_SIAFI
as NU5_29_, papelpesso0_.DT_ENVIO_CREDOR_SIAFI as DT6_29_,
papelpesso0_.DT_RETORNO_CREDOR_SIAFI as DT7_29_, papelpesso0_.ST_RESPONSAVEL
as ST8_29_,
papelpesso0_.CO_ENTIDADE as CO9_29_, papelpesso0_.CO_DIRIGENTE as CO10_29_,
papelpesso0_.CO_CARGO as CO11_29_ from RL_ENTIDADE_DIRIGENTE papelpesso0_
where papelpesso0_.CO_DIRIGENTE=28071|select
papelpesso0_.ID_ENTIDADE_DIRIGENTE as ID1_, papelpesso0_.DT_INICIO_MANDATO
as DT2_29_, papelpesso0_.DT_FIM_MANDATO as DT3_29_,

Re: Java process segfaulting and using 100% CPU

2006-04-19 Thread David Delbecq
Hi,

or other processes may end up using 100% CPU as well and presenting the
same behavior while on strace

If you mean also non java processes have similar problems, randomly, i
bet you may have either an OS issue (which affect all processes
randomly) either an hardware issue (corrupting RAM segments?)

If you want to discover where you tomcat is eating all it's CPU cycle, i
recommend you issue a 'kill -3 java process id', this will dump in
java stdout a list of current stacktrace, including native frames. You
might get there hints on what is problematic (might simply be an
HttpThread in a webapp endless loop)

Regards

Gustavo Noronha a écrit :

Hello,

I've searched a lot about this issue on the web, but did not find a
solution. I have the following setup:

Debian GNU/Linux 3.1 with official Tomcat5 package (5.0.30),
java-package-built Sun JVM:

# java -version
java version 1.5.0_05
Java(TM) 2 Runtime Environment, Standard Edition (build 1.5.0_05-b05)
Java HotSpot(TM) Server VM (build 1.5.0_05-b05, mixed mode)

Our main application uses Hibernate to persist objects and C3P0 to control
the connection pool. Here's the configuration file:

hibernate.connection.driver_class com.p6spy.engine.spy.P6SpyDriver
hibernate.connection.url jdbc:oracle:thin:@dbhost:1521:sid
hibernate.connection.username user
hibernate.connection.password pass
hibernate.transaction.factory_class =
org.hibernate.transaction.JDBCTransactionFactory
hibernate.use_outer_join true
hibernate.show_sql false
hibernate.c3p0.minPoolSize = 10
hibernate.c3p0.maxPoolSize = 200;
hibernate.c3p0.min_size=10
hibernate.c3p0.max_size=200
hibernate.c3p0.timeout=5000
hibernate.c3p0.max_statements=0
hibernate.cglib.use_reflection_optimizer=true
hibernate.dialect org.hibernate.dialect.OracleDialect

I use the P6SpyDriver to be able to log the SQL queries that go through to
the Oracle database, but I have the same problem with the OracleDriver as
well. So here's the problem:

After some time running one java process begins using 100% CPU; strace shows
this:

--- SIGSEGV (Segmentation fault) @ 0 (0) ---
rt_sigreturn(0x55d32bda)= -442421359
futex(0x805c770, FUTEX_WAIT, 2, NULL)   = -1 EAGAIN (Resource temporarily
unavailable)
futex(0x81ff918, FUTEX_REQUEUE, 1, 2147483647, 0x805c770) = 1
futex(0x805c770, FUTEX_WAKE, 1) = 1
futex(0x805c7f0, FUTEX_WAIT, 2, NULL)   = 0
futex(0x805c7f0, FUTEX_WAKE, 1) = 0
--- SIGSEGV (Segmentation fault) @ 0 (0) ---
rt_sigreturn(0x500ddbda)= -442421359
futex(0x805c770, FUTEX_WAIT, 2, NULL)   = 0
futex(0x81ff918, FUTEX_REQUEUE, 1, 2147483647, 0x805c770) = 1
futex(0x805c770, FUTEX_WAKE, 1) = 1
futex(0x805c7f0, FUTEX_WAIT, 2, NULL)   = 0
futex(0x805c7f0, FUTEX_WAKE, 1) = 0

This may stay like that for the whole day, tomcat being responsive, or other
processes may end up using 100% CPU as well and presenting the same behavior
while on strace. Eventually, tomcat may become unresponsive, but I could not
estabilish a pattern. I found similar SIGSEGV/futex behavior on a
non-100%-using process, too:

send(23,
\2c\0\0\6\0\0\0\0\0\21i\0\1\1\1\1\1\3^\0\2\200!\0\1\2\2\\1\1\r\0\0\0\0\4\177\377\377\377\0\0\0\0\0\0\0\0\0select
papelpesso0_.ID_ENTIDADE_DIRIGENTE as ID1_, papelpesso0_.DT_INICIO_MANDATO
as DT2_29_, papelpesso0_.DT_FIM_MANDATO as DT3_29_,
papelpesso0_.DT_NOMEACAO_DIRIGENTE as DT4_29_, papelpesso0_.NU_REMESSA_SIAFI
as NU5_29_, papelpesso0_.DT_ENVIO_CREDOR_SIAFI as DT6_29_,
papelpesso0_.DT_RETORNO_CREDOR_SIAFI as DT7_29_, papelpesso0_.ST_RESPONSAVEL
as ST8_29_, papelpesso0_.CO_ENTIDADE as CO9_29_, papelpesso0_.CO_DIRIGENTE
as CO10_29_, papelpesso0_.CO_CARGO as CO11_29_ from RL_ENTIDADE_DIRIGENTE
papelpesso0_ where
papelpesso0_.CO_DIRIGENTE=28071\1\1\0\0\0\0\0\0\1\1\0\0\0\0\0, 611, 0) =
611
recv(23, \1\217\0\0\6\0\0\0, 8, 0)= 8
recv(23, \0\0\20\31\0279
\273t6X\203\0\0xj\4\22\27\0220\4\31\0\0\0\0\0\0\1\201\1\v7\2\0\t\0\1\26\0\0\0\0\0\0\0\0\4\1\4\4ID1_\0\0\f\0\0\0\1\1\0\0\0\0\0\0\0\1\7\1\7\7DT2_29_\0\0\f\0\0\0\1\1\0\0\0\0\0\0\0\1\7\1\7\7DT3_29_\0\0\f\0\0\0\1\1\0\0\0\0\0\0\0\1\7\1\7\7DT4_29_\0\0\1\200\0\0\1\5\0\0\0\0\1\37\1\1\5\1\7\1\7\7NU5_29_\0\0\f\0\0\0\1\1\0\0\0\0\0\0\0\1\7\1\7\7DT6_29_\0\0\f\0\0\0\1\1\0\0\0\0\0\0\0\1\7\1\7\7DT7_29_\0\0`\200\0\0\1\1\0\0\0\0\1\37\1\1\1\1\7\1\7\7ST8_29_\0\0\2\0\f\0\1\26\0\0\0\0\0\0\0\0\7\1\7\7CO9_29_\0\0\2\0\n\0\1\26\0\0\0\0\0\0\0\0\10\1\10\10CO10_29_\0\0\2\0\t\0\1\26\0\0\0\0\0\0\0\0\10\1\10\10CO11_29_\0\0\1\7\7xj\4\23\2!\17\10\1\5\3+\367Y\0\1\1\0\0\0\0\4\0\0\0\0\1\1\2\1\332\3\0\0\0\0\0\2\177|\1\1\0\2\317/\1\5\0\0\0\0\1\1,
391, 0) = 391
send(23, \0\21\0\0\6\0\0\0\0\0\3\5\0\1\1\1\n, 17, 0) = 17
recv(23, \0F\0\0\6\0\0\0, 8, 0)   = 8
recv(23, \0\0\4\0\2\5{\0\0\1\1\0\3\0\1
\0\0\0\2\177|\1\1\0\2\317/\1\5\0\0\0\0\1\1\31ORA-01403: no data found\n,
62, 0) = 62
gettimeofday({1145421443, 130050}, NULL) = 0
gettimeofday({1145421443, 130213}, NULL) = 0
write(14, 1145421443130|17|37|statement|select
papelpesso0_.ID_ENTIDADE_DIRIGENTE as ID1_, 

Re: Java process segfaulting and using 100% CPU

2006-04-19 Thread Gustavo Noronha
2006/4/19, David Delbecq [EMAIL PROTECTED]:

 Hi,


Hey!

or other processes may end up using 100% CPU as well and presenting the
 same behavior while on strace


If you mean also non java processes have similar problems, randomly, i
 bet you may have either an OS issue (which affect all processes
 randomly) either an hardware issue (corrupting RAM segments?)


No, java processes only. And tomcat is the only java-using application
running on these servers.

If you want to discover where you tomcat is eating all it's CPU cycle, i
 recommend you issue a 'kill -3 java process id', this will dump in
 java stdout a list of current stacktrace, including native frames. You
 might get there hints on what is problematic (might simply be an
 HttpThread in a webapp endless loop)


Any hints on how to associate a thread with an OS PID? Or any other way of
identifying what thread is the culprit? I have played with the kill -3
feature, but didn't get very far investigating the output. =(

Thanks!

--
Gustavo Noronha Silva
Coordenação de Segurança e Sustentação
Ministério do Desenvolvimento Social - Brasil


Re: Java process segfaulting and using 100% CPU

2006-04-19 Thread opensta

Just Type kill -QUIT pid-of-process command you will get the thread dump in
catalina.out file of tomcat log folder 

u can identify the ur thread which are culprit from that
--
View this message in context: 
http://www.nabble.com/Java-process-segfaulting-and-using-100-CPU-t1474571.html#a4001573
Sent from the Tomcat - User forum at Nabble.com.


-
To unsubscribe, e-mail: [EMAIL PROTECTED]
For additional commands, e-mail: [EMAIL PROTECTED]