Re: Understanding GC Logs
Upon more profiling, I figured that I have lots of apache.axis objects that
are not garbage collected.
The way I am making SOAP calls is through axis1.4 generated stubs. Eg.
MyDAO {
protected MyPortType getAPIConnection() throws Exception {
MyPort port;
try {
MyServiceLocator service = new MyServiceLocator();
port = service.getMy(“http://someendpoint.com”);
} catch (Exception e) {
throw new MyException(“Exception occured”);
}
return port;
}
}
public class AccountDAOImpl extends MyDAO implements AccountDAO {
public AccountTO fetchAccount(User user) throws MyException {
AccountTO account;
try {
MyPort port = fetchAPIConnection();
account = port.fetchAccount(user);
} catch (Exception e) {
throw new MyException(“Exception occured”)
}
return account;
}
}
Shouldn't the 'port' object get collected once ?
--
View this message in context:
http://www.nabble.com/Understanding-GC-Logs-tp23862354p23984169.html
Sent from the Tomcat - User mailing list archive at Nabble.com.
-
To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org
For additional commands, e-mail: users-h...@tomcat.apache.org
Re: Understanding GC Logs
- what was hanging on to the 0.5Gb of memory in the 15 second period above between the 2nd and 3rd GC. I have a caching layer which is configured to evict objects from memory after 3 minutes of idle time. I have profiled and see all those objects in cache get evicted after some idle time. Is the pause times really too long compared to the throughput (99.6)? If so I probably could decrease the size of heap to make GC more frequent. -- View this message in context: http://www.nabble.com/Understanding-GC-Logs-tp23862354p23870052.html Sent from the Tomcat - User mailing list archive at Nabble.com. - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
RE: Understanding GC Logs
If what you're caching is large arrays, you might want to consider breaking them up into smaller chunks of the same size, and pooling those. Not sure what you mean by pooling those. I am using JBoss cache. You might also think about tracking your cache entries via SoftReference objects, thus letting GC throw them away when space gets tight. You mean using -XX:SoftRefLRUPolicyMSPerMB=N ? -- View this message in context: http://www.nabble.com/Understanding-GC-Logs-tp23862354p23871748.html Sent from the Tomcat - User mailing list archive at Nabble.com. - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Understanding GC Logs
I am just trying to learn and understand the GC logs. (I did read the sun's docs on GC tuning). jdk1.6.0_07 -Xms2g -Xmx2g -Xss256k -XX:+UseLargePages -XX:+PrintGCDetails -verbose:gc -Xloggc:/var/log/gc.log -XX:PermSize=512m -XX:MaxPermSize=512m It is running Parallel Collector by default. The full GC usually runs in every 20-30 minutes (takes 2 seconds), and the minor collections occur every 40-50 seconds. I viewed the logs in GC Viewer, and the throughput is about 99.6%, but the pauses tend to get noticable at times slowing the app down for upto 10 minutes- and sometimes the app becomes unresponsive after running for about a week due to GC. I have pasted the snipped from my GC logs (when the pause became noticeable). Does the logs in themselves indicates any possible problems? Thanks in advance. 322241.484: [GC [PSYoungGen: 493731K-50938K(578816K)] 1617970K-1175624K(1977600K), 0.0761440 secs] [Times: user=0.23 sys=0.00, real=0.07 secs] 322264.254: [GC [PSYoungGen: 508730K-78771K(581568K)] 1633416K-1203628K(1980352K), 0.1524060 secs] [Times: user=0.26 sys=0.01, real=0.16 secs] 322283.883: [GC [PSYoungGen: 543155K-118014K(582400K)] 1668012K-1249096K(1981184K), 0.2397130 secs] [Times: user=0.49 sys=0.00, real=0.24 secs] 322301.402: [GC [PSYoungGen: 582398K-118007K(495360K)] 1713480K-1289473K(1894144K), 0.2343380 secs] [Times: user=0.64 sys=0.01, real=0.24 secs] 322317.408: [GC [PSYoungGen: 495351K-161534K(538880K)] 1666817K-1357597K(1937664K), 0.3078690 secs] [Times: user=0.70 sys=0.00, real=0.31 secs] 322338.991: [GC [PSYoungGen: 538878K-161533K(426240K)] 1734941K-1379949K(1825024K), 0.1890400 secs] [Times: user=0.86 sys=0.00, real=0.19 secs] 322352.173: [GC [PSYoungGen: 426237K-156891K(421632K)] 1644653K-1376348K(1820416K), 0.1314940 secs] [Times: user=0.83 sys=0.00, real=0.13 secs] 322353.537: [GC [PSYoungGen: 421595K-149135K(464320K)] 1641052K-1368592K(1863104K), 0.1075660 secs] [Times: user=0.78 sys=0.01, real=0.11 secs] 322358.922: [GC [PSYoungGen: 385935K-192657K(429504K)] 1605392K-1412114K(1828288K), 0.4118000 secs] [Times: user=1.10 sys=1.27, real=0.41 secs] 322382.445: [GC [PSYoungGen: 429457K-162415K(466944K)] 1648914K-1391845K(1865728K), 0.1753080 secs] [Times: user=0.93 sys=0.13, real=0.18 secs] 322389.711: [GC [PSYoungGen: 395887K-175021K(466944K)] 1625317K-1404944K(1865728K), 0.1825450 secs] [Times: user=0.83 sys=0.01, real=0.18 secs] 322400.876: [GC [PSYoungGen: 408493K-163512K(466944K)] 1638416K-1397305K(1865728K), 0.1612630 secs] [Times: user=0.87 sys=0.01, real=0.16 secs] 322411.500: [GC [PSYoungGen: 396239K-111767K(466944K)] 1630032K-1412129K(1865728K), 0.2211210 secs] [Times: user=1.04 sys=0.11, real=0.23 secs] 322427.250: [GC [PSYoungGen: 345239K-35751K(466944K)] 1645601K-1401444K(1865728K), 0.1585970 secs] [Times: user=0.65 sys=0.14, real=0.16 secs] 322427.409: [Full GC [PSYoungGen: 35751K-0K(466944K)] [PSOldGen: 1365693K-695195K(1398784K)] 1401444K-695195K(1865728K) [PSPermGen: 180694K-180694K(524288K)], 2 .3017070 secs] [Times: user=2.09 sys=0.21, real=2.30 secs] 322431.641: [GC [PSYoungGen: 233472K-3639K(466944K)] 928667K-698834K(1865728K), 0.0171480 secs] [Times: user=0.05 sys=0.00, real=0.02 secs] 322432.659: [GC [PSYoungGen: 237111K-4086K(466944K)] 932306K-699281K(1865728K), 0.0150920 secs] [Times: user=0.04 sys=0.00, real=0.01 secs] 322438.955: [GC [PSYoungGen: 237558K-10227K(466944K)] 932753K-705422K(1865728K), 0.0291110 secs] [Times: user=0.06 sys=0.01, real=0.03 secs] 322441.277: [GC [PSYoungGen: 243699K-7492K(466944K)] 938894K-702688K(1865728K), 0.0213000 secs] [Times: user=0.05 sys=0.01, real=0.03 secs] 322442.216: [GC [PSYoungGen: 240964K-15236K(466944K)] 936160K-711474K(1865728K), 0.0242510 secs] [Times: user=0.11 sys=0.00, real=0.03 secs] 322449.748: [GC [PSYoungGen: 248708K-22608K(466944K)] 944946K-723379K(1865728K), 0.0357610 secs] [Times: user=0.19 sys=0.01, real=0.04 secs] 322451.245: [GC [PSYoungGen: 256080K-2982K(466944K)] 956851K-724151K(1865728K), 0.0365930 secs] [Times: user=0.20 sys=0.04, real=0.04 secs] 322452.165: [GC [PSYoungGen: 236454K-6013K(472000K)] 957623K-728651K(1870784K), 0.0160030 secs] [Times: user=0.07 sys=0.01, real=0.02 secs] 322457.810: [GC [PSYoungGen: 244541K-14396K(466944K)] 967179K-737034K(1865728K), 0.0434880 secs] [Times: user=0.14 sys=0.09, real=0.05 secs] 322463.141: [GC [PSYoungGen: 252924K-19285K(492928K)] 975562K-741923K(1891712K), 0.0314660 secs] [Times: user=0.15 sys=0.03, real=0.04 secs] 322471.247: [GC [PSYoungGen: 293781K-70034K(481984K)] 1016419K-792671K(1880768K), 0.1132550 secs] [Times: user=0.48 sys=0.15, real=0.11 secs] 322472.328: [GC [PSYoungGen: 344530K-156662K(452672K)] 1067167K-879300K(1851456K), 0.1949290 secs] [Times: user=0.98 sys=0.40, real=0.20 secs] 322476.209: [GC [PSYoungGen: 409974K-188250K(441600K)] 1132612K-918748K(1840384K), 0.1994430 secs] [Times: user=1.11 sys=0.19, real=0.20 secs] 322478.163: [GC [PSYoungGen: 441562K-200628K(466944K)] 1172060K-967015K(1865728K),
Tomcat Concurrent Requests
Given that each request takes 2 seconds on average. Among them, some of them take less than 500ms, and some take as long as 5 seconds or even a little more sometimes. How many such concurrent request would a tomcat server running on a double quad-core server handle? I am trying to understand the relation between CPU, response time and no of concurrent requests. -- View this message in context: http://www.nabble.com/Tomcat-Concurrent-Requests-tp23815501p23815501.html Sent from the Tomcat - User mailing list archive at Nabble.com. - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
RE: Tomcat Concurrent Requests
The 5 seconds calls are all database or webservice calls. So they all go to waiting state. I did some load tests using JMeter, but I had problems coming to a conclusion with the data. What should I look for exactly? Because as I increase the no of concurrent requests, the app starts responding slower and slower. -- View this message in context: http://www.nabble.com/Tomcat-Concurrent-Requests-tp23815501p23816012.html Sent from the Tomcat - User mailing list archive at Nabble.com. - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: Apache, Tomcat, Mod_JK Configurations
Ok.. adding some info to mod jk logs and doing some thread and heap dumps, I figured that, during peak traffic hours, the garbage collection gets more frequest and takes longer. This slows down the overall system and the threads start piling up. Requests that used to take 2 seconds now take a couple of hundred seconds. The application isn't using the swap space though. It takes a long as 15 minutes for the system to recover completely and sometimes I have to restart. Now how can I intelligently use the timeout settings to kill the long running requests and prevent threads from making it worse? In httpd.conf, I have: Timeout 120 In worker.properties, I have: worker.node1.connection_pool_timeout=600 In the tomcat AJP connector, I have: connectionTimeout=60 How can I ensure that no request is taking longer than 3 minutes? -- View this message in context: http://www.nabble.com/Apache%2C-Tomcat%2C-Mod_JK-Configurations-tp23751902p23817845.html Sent from the Tomcat - User mailing list archive at Nabble.com. - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: Apache, Tomcat, Mod_JK Configurations
The problem has always occured at the oddest hours for me to do a thread dump. I have done jmeter load test and tried to recreate the problem in test, but have never able. I will upgrade to the latest version and then play with the connection timeouts. CrystalCracker wrote: Apache 2.2 Tomcat 6 Mod_jk 1.2.21 All of them are running on the same box. I have at any given time around 300 active sessions using the site, and upto 450 at max. Each user on average logs on to the site for around 15 minutes, and the calls are usually big and slow database or web- service calls to various backend systems. The session time out is 30 minutes, but a few users stay logged in for hours. My Major settings are: //Apache httpd.conf KeepAlive Off Timeout 120 IfModule prefork.c StartServers 8 MinSpareServers5 MaxSpareServers 20 ServerLimit 512 MaxClients 512 MaxRequestsPerChild 4000 /IfModule //Tomcat server.xml !-- Define an AJP 1.3 Connector on port 8009 -- Connector port=8009 protocol=AJP/1.3 redirectPort=8443 maxThreads=512 minSpareThreads=5 maxSpareThreads=20 / //Modjk worker.properties worker.node1.port=8009 worker.node1.host= localhost worker.node1.type=ajp13 worker.node1.lbfactor=1 All other settings are using default values. Everything is working fine, except that I see a huge spike in Apache threads and Tomcat threads (all 512 threads are used) every few days, and it becomes literally unresponive for 10-15 minutes. The no of requests is as usual and Garbage collection and memory usage seems to be fine. Sometimes it recovers itself, and but most of the time I end up restarting the servers. Upon looking at the mod_jk logs I see a lot of the following, but there are no errors on tomcat side: [Tue May 26 13:38:45 2009][30302:33088] [error] ajp_get_reply::jk_ajp_common.c (1580): (node1) Tomcat is down or refused connection. No response has been sent to the client (yet) [Tue May 26 13:38:45 2009][30302:33088] [info] ajp_service::jk_ajp_common.c (1891): (node1) receiving from tomcat failed, recoverable operation attempt=0 [Tue May 26 13:38:45 2009][30302:33088] [info] ajp_service::jk_ajp_common.c (1930): (node1) sending request to tomcat failed, recoverable operation attempt=1 [Tue May 26 13:38:46 2009][30305:33088] [error] ajp_connection_tcp_get_message::jk_ajp_common.c (951): (node1) can't receive the response message from tomcat, network problems or tomcat (127.0.0.1:800 9) is down (errno=104) [Tue May 26 13:38:46 2009][30305:33088] [error] ajp_get_reply::jk_ajp_common.c (1580): (node1) Tomcat is down or refused connection. No response has been sent to the client (yet) [Tue May 26 13:38:46 2009][30305:33088] [info] ajp_service::jk_ajp_common.c (1891): (node1) receiving from tomcat failed, recoverable operation attempt=0 Is my configuration suited for the kind of load I have? I think errno=104 means modjk thinks tomcat is down. Why would that happen? Any advices? Thanks a lot. -- View this message in context: http://www.nabble.com/Apache%2C-Tomcat%2C-Mod_JK-Configurations-tp23751902p23769058.html Sent from the Tomcat - User mailing list archive at Nabble.com. - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Apache, Tomcat, Mod_JK Configurations
Apache 2.2 Tomcat 6 Mod_jk 1.2.21 All of them are running on the same box. I have at any given time around 300 active sessions using the site, and upto 450 at max. Each user on average logs on to the site for around 15 minutes, and the calls are usually big and slow database or web- service calls to various backend systems. The session time out is 30 minutes, but a few users stay logged in for hours. My Major settings are: //Apache httpd.conf KeepAlive Off Timeout 120 IfModule prefork.c StartServers 8 MinSpareServers5 MaxSpareServers 20 ServerLimit 512 MaxClients 512 MaxRequestsPerChild 4000 /IfModule //Tomcat server.xml !-- Define an AJP 1.3 Connector on port 8009 -- Connector port=8009 protocol=AJP/1.3 redirectPort=8443 maxThreads=512 minSpareThreads=5 maxSpareThreads=20 / //Modjk worker.properties worker.node1.port=8009 worker.node1.host= localhost worker.node1.type=ajp13 worker.node1.lbfactor=1 All other settings are using default values. Everything is working fine, except that I see a huge spike in Apache threads and Tomcat threads (all 512 threads are used) every few days, and it becomes literally unresponive for 10-15 minutes. The no of requests is as usual and Garbage collection and memory usage seems to be fine. Sometimes it recovers itself, and but most of the time I end up restarting the servers. Upon looking at the mod_jk logs I see a lot of the following, but there are no errors on tomcat side: [Tue May 26 13:38:45 2009][30302:33088] [error] ajp_get_reply::jk_ajp_common.c (1580): (node1) Tomcat is down or refused connection. No response has been sent to the client (yet) [Tue May 26 13:38:45 2009][30302:33088] [info] ajp_service::jk_ajp_common.c (1891): (node1) receiving from tomcat failed, recoverable operation attempt=0 [Tue May 26 13:38:45 2009][30302:33088] [info] ajp_service::jk_ajp_common.c (1930): (node1) sending request to tomcat failed, recoverable operation attempt=1 [Tue May 26 13:38:46 2009][30305:33088] [error] ajp_connection_tcp_get_message::jk_ajp_common.c (951): (node1) can't receive the response message from tomcat, network problems or tomcat (127.0.0.1:800 9) is down (errno=104) [Tue May 26 13:38:46 2009][30305:33088] [error] ajp_get_reply::jk_ajp_common.c (1580): (node1) Tomcat is down or refused connection. No response has been sent to the client (yet) [Tue May 26 13:38:46 2009][30305:33088] [info] ajp_service::jk_ajp_common.c (1891): (node1) receiving from tomcat failed, recoverable operation attempt=0 Is my configuration suited for the kind of load I have? I think errno=104 means modjk thinks tomcat is down. Why would that happen? Any advices? Thanks a lot. -- View this message in context: http://www.nabble.com/Apache%2C-Tomcat%2C-Mod_JK-Configurations-tp23751902p23751902.html Sent from the Tomcat - User mailing list archive at Nabble.com. - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
How does Prefork work?
Can anyone explain me how exactly prefork works? StartServers 2 MaxClients 150 MinSpareThreads 25 MaxSpareThreads 75 ThreadsPerChild 25 ServerLimit 16 I think I got confused between the terms - server, process and thread. If prefork is a single thread process, what does that ThreadsPerChild mean for prefork? -- View this message in context: http://www.nabble.com/How-does-Prefork-work--tp23754923p23754923.html Sent from the Tomcat - User mailing list archive at Nabble.com. - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
