한국은 왜 Software의 변두리에만 머물러 있을까...
Enterprise Java 2007.09.19 22:38(물론 영어로... ^^)
Java나 Oracle Forum 사이트들을 볼 때 마다, 그리고 Google에서 기술적인 내용을 검색할 때마다 자괴감에 빠지곤 한다.
대한민국의 엔지니어들은 언제쯤 저 영어의 바다에 떠 있는 Software의 주류에 들어갈 수 있을까?
아니, 언제쯤 그들만의 리그가 아닌 대한민국의 리그를 만들 수 있을까?
내 주위나 온라인 상에서 가끔 출중한 실력을 갖춘 엔지니어들을 볼 때가 있다.
하지만 어느 누구도 태생의 한계에서 벗어나지 못한다.
아무리 실력이 좋아도 대한민국이라는 좁은 세계에 갇혀 지낼 수 밖에 없는 운명이다.
안타깝게도 이게 현실이다.
대한민국의 이 많은 엔지니어들이 영어로 자신의 생각을 표현하고, 질문하고 대답할 수 있다면
그 순간 대한민국 Software의 영역과 시장성이 글로벌한 수준으로 올라간다.
그래서 나는 어떤 개인적인 이익을 위해서라기 보다는
대한민국 Software 업계의 수준을 전세계에 알리는 서곡을 울린다는 마음으로
가끔 영어로 글을 적기도 하고, 미국놈이나 인도놈, 유럽놈들이 설쳐대는 온라인 세계에서
가끔 어줍짢은 영어를 주고 받기도 한다.
그런 차원에서 앞으로 이 블로그에 내가 참가한 Forum(의 Article을 가끔 올릴까 한다.
언젠가 대한민국의 똘똘한 엔지니어들이 온라인 세계에서 미국놈들한테 한 수 가르치고 있을 날을 기대해보면서...
=====================================================================================
아래 내용은 http://forum.sun.java.com 에서 올라온 질문에 대해 토의 내용이다.
Dion_Cho 라는 닉네임으로 활동중... ^^;
진짜배기 코쟁이 고수들에 비해 초라한 영어와 지식을 구사하고 있다. ^^;
Exorbitant Garbage Collection Times Aug 17, 2007 9:10 AM | |||
Once a day, at around 4-4:30am, our application experiences a singleFull GC with taking an exorbitant amount of time. A Full GC kicks inand pauses all threads for 5 to 30 minutes. Full GC's regularly occurat other times and complete in 5-20 seconds. Anyone seen this or anyhave any ideas about this? Example of normal GC that occurs frequently throughout the day: [Full GC[Unloading class $Proxy136] .... 4632722K->1616289K(6141952K), 14.9400110 secs] Example of ridiculously long GC that occurs daily at 4-4:30am: [Full GC[Unloading class sun.reflect.GeneratedSerializationConstructorAccessor455] .... 5456231K->2017269K(6141952K), 492.0402160 secs] Here's our VM params: -server -XX:-OmitStackTraceInFastThrow -Xincgc -XX:+CMSIncrementalMode-XX:+CMSIncrementalPacing -XX:MaxGCPauseMillis=20000-XX:+DisableExplicitGC -XX:NewSize=1500m -XX:SurvivorRatio=18-verbose:gc -Xms6000M -Xmx6000M We're running Java 1.6 on Linux, Redhat 3. | |||
Re: Exorbitant Garbage Collection Times Aug 17, 2007 9:29 AM (reply 1 of 5) | |||
By the way I should point out that this is a very powerful Linux serverand is hosting only this application. During the long Full GC, the loadon the server is relatively low. | |||
Re: Exorbitant Garbage Collection Times Aug 17, 2007 5:13 PM (reply 2 of 5) | |||
If you post the output of running with -XX:+PrintGCTimeStamps -XX:+PrintGCDetails (and without-verbose:gc, please) we can give more advice. If the logs are too longto post, you can email them HotSpotGC-Feedback (at) Sun.COM. Pleaseinclude your full command line (e.g., the one you show omits at least"-d64"). From the little you've shown, it sounds like most of the time CMS cankeep up with your rate of garbage generation, but something happensaround 4AM that causes it to "lose the race" and bail out to a fullmark-compact collection. That's a single-threaded stop-the-worldcollector, and won't meet your pause time goals. The logs would say. The other possibility is that your Java application is idle around 4AM,but something else is running on the machine and forces the 6GB of yourheap out to disk. then the next collection will have to page all thatback in. That might account for 10 (or even 30) minutes for acollection. Or it could be a combination: CMS might start a concurrentcollection, but paging might cause it to take so long that it bails outto the stop-the-world collector. That might be harder to see from thelogs, but we are pretty good at reading logs. | |||
Re: Exorbitant Garbage Collection Times Aug 21, 2007 6:51 PM (reply 3 of 5) | |||
Thanks very much for your suggestions. Unfortunately it seems like neither applies for these reasons: 1. This is an extremely low-activity period of time for thisapplication, as it's a trading application used primarily for USmarkets and secondarily for Asian markets, and this time is outside USand almost all Asian markets. 2. There should be absolutely nothing else running on this machine, asit's dedicated to this application. The having been paged out doesdefinitely seem to be the most likely explanation, but I just don'tunderstand why it was paged out... I'll get you the logs as requested this week. | |||
Re: Exorbitant Garbage Collection Times Sep 13, 2007 7:34 AM (reply 4 of 5) | |||
Just experienced a 498 second (yikes!) garbage collection pause. Theentry from the log is below (we added -XX:+PrintGCTimeStamps-XX:+PrintGCDetails and removed -verbose:gc). I will also send theentire log to the email address you have provided. Note that we actually reduced our Xmx to 4000M (from 6000M) despitethis machine having 8gig physical ram in the hopes that this wouldprevent any paging, and it seems to have drastically improved thesituation - these exorbitant pauses now occur only very seldomly. This is the full command we're justing to start the JBoss JVM: /proj/bo/apps/jdk/production/bin/java -Dprogram.name=run.sh -server -XX:-OmitSta ckTraceInFastThrow -Xincgc -XX:+CMSIncrementalMode -XX:+CMSIncrementalPacing -XX:MaxGCPauseMillis=20000 -XX:+DisableExplicitGC -XX:NewSize=1500m -XX:SurvivorRatio=18 -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -Djava.endorsed.dirs=/var/local/jboss/jboss-c urrent/lib/endorsed -Dsystem.state=production -Dcom.hb.common.api.util.Environment.app.name=Hermes -Djboss.partition.name=as20. nyc.hcmny.com -Dorg.jboss.security.SecurityAssociation.ThreadLocal=true -Doracle.net.tns_admin=/var/opt/oracle/etc -Djnp.discov eryPort=1103 -classpath /var/local/jboss/jboss-current/bin/run.jar:/proj/bo/apps/jdk/production/lib/tools.jar -Xms4000M -Xmx400 0M -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.port=8134 -Dcom.sun.management.jmxremote.authenticate=true -Dc om.sun.management.jmxremote.ssl=false -Dcom.sun.management.jmxremote.password.file=/proj/bo/jmxremote.password org.jboss.Main - cdefault This is the exact JRE we're using: java version "1.6.0" Java(TM) SE Runtime Environment (build 1.6.0-b105) Java HotSpot(TM) 64-Bit Server VM (build 1.6.0-b105, mixed mode) Here's the 498 second GC pause: 103999.802: [GC 103999.802: [ParNew (promotion failed):1459200K->1459200K(1459200K), 478.7897900 secs]104478.592:[CMS104483.552: [CMS-concurrent-mark: 5.170/491.280 secs] (concurrent mode failure)[Unloading class sun.reflect.GeneratedSerializationConstructorAccessor605] [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor866] [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor870] [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor887] [Unloading class sun.reflect.GeneratedMethodAccessor267] [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor864] [Unloading class sun.reflect.GeneratedConstructorAccessor148] [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor861] [Unloading class sun.reflect.GeneratedMethodAccessor268] [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor606] [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor862] [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor886] [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor706] [Unloading class sun.reflect.GeneratedConstructorAccessor145] [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor865] [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor350] [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor860] [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor868] [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor863] [Unloading class sun.reflect.GeneratedConstructorAccessor147] [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor867] [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor869] [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor185] [Unloading class sun.reflect.GeneratedConstructorAccessor125] [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor871] [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor707] [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor708] : 2517456K->2073715K(2560000K), 19.7399910 secs] 3927185K->2073715K(4019200K) icms_dc=5 , 498.5297810 secs] at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:96) at java.net.SocketOutputStream.write(SocketOutputStream.java:136) at java.io.ObjectOutputStream$BlockDataOutputStream.drain(ObjectOutputStream.java:1838) at java.io.ObjectOutputStream$BlockDataOutputStream.setBlockDataMode(ObjectOutputStream.java:1747) at java.io.ObjectOutputStream. 21:37:07,931 WARN [TransactionImpl] TransactionTransactionImpl:XidImpl[FormatId=257,GlobalId=as20.nyc.hcmny.com/163214, BranchQual=, localId=163214] timedout. status=STATUS_ACTIVE 2007-09-12 21:37:08 | |||
Re: Exorbitant Garbage Collection Times Sep 13, 2007 6:38 PM (reply 5 of 5) | |||
Exact answer will be given by Sun. :) Your exorbitant full gc time seems to be caused by promotion failure as the log says. My suggestion is 1) New generation seems big. Especially under CMS. It might causepromotion failure. Decrease new generation size. 500M ~ 1G seems to befine(And optionally decrease -XX:SurvivorRatio to 8) 2) Try -XX:CMSInitiatingOccupancyFraction=55 or 50. Lower value willnot harm, only with negligible side effect. It will initate concurrentcollection more agressively to reduce promotion failure. Optionallyapply -XX:+UseCMSInitiatingOccupancyOnly option. There are lots of discussions and answers in this forum about theperformance of CMS collector. Some search will you give great hints. |
|
'Enterprise Java' 카테고리의 다른 글
Java에서의 Out Of Memory Error(OOME)에 대한 나름대로의 정리... (5) | 2007.10.03 |
---|---|
Sun Java Forum - 잘못된 Young Generation 크기에 의한 Full GC 발생 (0) | 2007.09.22 |
한국은 왜 Software의 변두리에만 머물러 있을까... (3) | 2007.09.19 |
JMP - 공짜치곤 괜찮은 Java Profiler (0) | 2007.09.18 |
[Enterprise Java는 거대한 동기화 머신이다] - 재미있는 GC 성능 사례 - Part4 (0) | 2007.09.18 |