태터데스크 관리자

도움말
닫기
적용하기   첫페이지 만들기

태터데스크 메시지

저장하였습니다.

한국은 왜 Software의 변두리에만 머물러 있을까...

Enterprise Java 2007.09.19 22:38
요즘 공부삼아 Sun Java Forum(http://forum.sun.java.com)에 들르곤 한다. 그리고 아는 내용이 나오면 답변도 달기도 한다.
(물론 영어로... ^^)

Java나 Oracle Forum 사이트들을 볼 때 마다, 그리고 Google에서 기술적인 내용을 검색할 때마다 자괴감에 빠지곤 한다.
대한민국의 엔지니어들은 언제쯤 저 영어의 바다에 떠 있는 Software의 주류에 들어갈 수 있을까?
아니, 언제쯤 그들만의 리그가 아닌 대한민국의 리그를 만들 수 있을까?

내 주위나 온라인 상에서 가끔 출중한 실력을 갖춘 엔지니어들을 볼 때가 있다.
하지만 어느 누구도 태생의 한계에서 벗어나지 못한다.
아무리 실력이 좋아도 대한민국이라는 좁은 세계에 갇혀 지낼 수 밖에 없는 운명이다.

안타깝게도 이게 현실이다.

대한민국의 이 많은 엔지니어들이 영어로 자신의 생각을 표현하고, 질문하고 대답할 수 있다면
그 순간 대한민국 Software의 영역과 시장성이 글로벌한 수준으로 올라간다.

그래서 나는 어떤 개인적인 이익을 위해서라기 보다는
대한민국 Software 업계의 수준을 전세계에 알리는 서곡을 울린다는 마음으로
가끔 영어로 글을 적기도 하고, 미국놈이나 인도놈, 유럽놈들이 설쳐대는 온라인 세계에서
가끔 어줍짢은 영어를 주고 받기도 한다.

그런 차원에서 앞으로 이 블로그에 내가 참가한 Forum(의 Article을 가끔 올릴까 한다.
언젠가 대한민국의 똘똘한 엔지니어들이 온라인 세계에서 미국놈들한테 한 수 가르치고 있을 날을 기대해보면서...

=====================================================================================
아래 내용은 http://forum.sun.java.com 에서 올라온 질문에 대해 토의 내용이다.
Dion_Cho 라는 닉네임으로 활동중... ^^;
진짜배기 코쟁이 고수들에 비해 초라한 영어와 지식을 구사하고 있다. ^^;


etolson@hcmny.com
Posts:14
Registered: 4/18/05
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.
etolson@hcmny.com
Posts:14
Registered: 4/18/05
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.
PeterKessler
Posts:77
Registered: 10/2/06
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.
etolson@hcmny.com
Posts:14
Registered: 4/18/05
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.
etolson@hcmny.com
Posts:14
Registered: 4/18/05
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.(ObjectOutputStream.java:226)
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
Dion_Cho
Posts:15
Registered: 9/6/07
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.
This topic has 5 replies on 1 page.

신고
Trackback 0 : Comments 3
  1. 강한구 2009.12.23 12:12 신고 Modify/Delete Reply

    1년전 대학교때 영어안하고 개발만해서 성공해야지라고 마음먹었던제가
    지금이되서야 '아.....영어는 선택이 아니라 필수구나.....'라는 마음을 가졌습니다.

    1년동안 어떤분야로 나갈지 고민하다가 DB만드는쪽으로 결정해서 공부하다가
    오게되었습니다. 좋은정보가 많이 있네요 : ) 감사합니다. 항상 건강하시고 2009년 마무리 잘하세요~~ : )

  2. 지우 2011.11.07 09:44 Modify/Delete Reply

    관리자의 승인을 기다리고 있는 댓글입니다

  3. moncler online 2013.01.05 16:35 Modify/Delete Reply

    관리자의 승인을 기다리고 있는 댓글입니다

Write a comment

티스토리 툴바