Re: Java process segfaulting and using 100% CPU
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
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
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
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/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
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
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
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/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
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
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
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/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
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]