2011-03-08 3 views
8

मैं प्रदर्शन ट्यूनिंग अनुप्रयोगों में एक नौसिखिया हूं और जीसी के कामकाज को समझ रहा हूं, इसलिए शायद एक ही प्रश्न पूछने के लिए दस लाखवें समय!मेरा ऐप लगातार पूर्ण जीसी चला रहा है!

समस्या यह है कि 2 - 3 सप्ताह पहले, किसी भी तरह कहीं मेरे वेब एप्लिकेशन ने हर बार क्रैश करना शुरू कर दिया था। लॉग को देखते हुए, यह निष्कर्ष निकाला गया था कि OOM त्रुटियों के कारण अपने क्रैश होने:

Caused by: java.sql.SQLException: java.lang.OutOfMemoryError: Java heap space 
    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1055) 
    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:956) 
    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:926) 
    at com.mysql.jdbc.Util.handleNewInstance(Util.java:430) 
    ... 

और

14:29:58,469 ERROR [[dispatcher]] Servlet.service() for servlet dispatcher threw exception 
java.lang.OutOfMemoryError: GC overhead limit exceeded 
    at org.hibernate.event.def.AbstractFlushingEventListener.flushEntities(AbstractFlushingEventListener.java:193) 
    at org.hibernate.event.def.AbstractFlushingEventListener.flushEverythingToExecutions(AbstractFlushingEventListener.java:76) 
    at org.hibernate.event.def.DefaultAutoFlushEventListener.onAutoFlush(DefaultAutoFlushEventListener.java:35) 
    at org.hibernate.impl.SessionImpl.autoFlushIfRequired(SessionImpl.java:969) 
    at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1114) 
    at org.hibernate.impl.QueryImpl.list(QueryImpl.java:79) 
    at com.tennisearth.dao.hibernate.HibernateCommentaryDao.getCommentary(HibernateCommentaryDao.java:52) 
    at com.tennisearth.service.impl.CommentaryServiceImpl.getCommentary(CommentaryServiceImpl.java:454) 
    at com.tennisearth.service.impl.CommentaryServiceImpl.getCommentaryMap(CommentaryServiceImpl.java:165) 
    at com.tennisearth.web.controllers.WidgetsController.commentaryList(WidgetsController.java:704) 
    at com.tennisearth.web.controllers.WidgetsController.widgets(WidgetsController.java:290) 
    at sun.reflect.GeneratedMethodAccessor259.invoke(Unknown Source) 
      ... 

बाद में, मैं जीसी लॉग प्रवेश करने शुरू कर दिया और पाया कि शुरू में जब सर्वर प्रारंभ होता है, जी सी ठीक चल रहा है :

3.808: [GC 56505K->5808K(251264K), 0.0120840 secs] 
3.820: [Full GC 5808K->5614K(251264K), 0.0540460 secs] 
7.169: [GC 71214K->9589K(251264K), 0.0068780 secs] 
8.173: [GC 75189K->13543K(251264K), 0.0174120 secs] 
8.624: [GC 79143K->13693K(251264K), 0.0088080 secs] 
9.907: [GC 79293K->16013K(251264K), 0.0132330 secs] 
11.832: [GC 81613K->22100K(311360K), 0.0227030 secs] 
13.338: [GC 136508K->38851K(316864K), 0.0346600 secs] 
13.373: [Full GC 38851K->38559K(316864K), 0.2093700 secs] 
15.113: [GC 164255K->45826K(331520K), 0.0151220 secs] 
18.946: [GC 177794K->58815K(322688K), 0.0254140 secs] 
22.699: [GC 186431K->70079K(322880K), 0.0500300 secs] 
40.246: [GC 191871K->78818K(311296K), 0.0429900 secs] 
41.280: [GC 196706K->81375K(324608K), 0.0340230 secs] 
42.798: [GC 199135K->82432K(324736K), 0.0074390 secs] 
43.487: [GC 200192K->85729K(394112K), 0.0098220 secs] 
45.564: [GC 274145K->97421K(394688K), 0.0212620 secs] 
46.829: [GC 285837K->100769K(491968K), 0.0287150 secs] 
48.011: [GC 388705K->106326K(491648K), 0.0275700 secs] 
51.035: [GC 394262K->114643K(493376K), 0.0199210 secs] 
58.073: [GC 407187K->118997K(493760K), 0.0190090 secs] 
61.094: [GC 411541K->122449K(496320K), 0.0181850 secs] 
83.288: [GC 419985K->128776K(467968K), 0.0206970 secs] 
91.216: [GC 414152K->136966K(459136K), 0.0237830 secs] 
108.336: [GC 410758K->137782K(445632K), 0.0158180 secs] 
116.492: [GC 400566K->139454K(434304K), 0.0126040 secs] 
139.645: [GC 391742K->140705K(420608K), 0.0113540 secs] 
150.825: [GC 383009K->158942K(428096K), 0.0375920 secs] 
151.909: [GC 391774K->178964K(437824K), 0.0677160 secs] 
153.518: [GC 417702K->280503K(496000K), 0.1514220 secs] 
153.669: [Full GC 280503K->274184K(618880K), 0.7686300 secs] 
155.431: [GC 468706K->366398K(658880K), 0.1449730 secs] 
155.579: [GC 366772K->364514K(603072K), 0.0524370 secs] 
155.631: [Full GC 364514K->348726K(753728K), 0.9406650 secs] 
157.072: [GC 508278K->395401K(733376K), 0.0369850 secs] 
157.839: [GC 554533K->473779K(762816K), 0.1072000 secs] 
159.105: [GC 614259K->509767K(771840K), 0.0883110 secs] 
163.696: [GC 650247K->516783K(748416K), 0.0878210 secs] 
163.784: [Full GC 516783K->512313K(920384K), 0.6153950 secs] 

लेकिन जाँच पर अगले दिन लॉग करता है, जी सी लॉग पूर्ण जेंटलमैन कैडेट दिखाने के लिए हर समय:

65515.860: [Full GC 815615K->763589K(932096K), 1.3774000 secs] 
65517.398: [Full GC 815615K->761150K(932096K), 1.3959730 secs] 
65518.920: [Full GC 815615K->770183K(932096K), 1.3627860 secs] 
65520.388: [Full GC 815615K->772928K(932096K), 1.3690040 secs] 
65521.849: [Full GC 815615K->777388K(932096K), 1.3932870 secs] 
65523.321: [Full GC 815615K->773739K(932096K), 1.6262920 secs] 
65525.032: [Full GC 815615K->782518K(932096K), 1.3857020 secs] 
65526.493: [Full GC 815615K->784568K(932096K), 1.3901050 secs] 
65528.031: [Full GC 815615K->743695K(932096K), 1.2809140 secs] 
65530.065: [Full GC 815615K->721823K(932096K), 1.3245560 secs] 
65538.982: [Full GC 815615K->729961K(932096K), 1.2241330 secs] 
65540.508: [Full GC 815615K->729519K(932096K), 1.2257770 secs] 
65542.135: [Full GC 815615K->731559K(932096K), 1.2206840 secs] 
65547.769: [Full GC 815615K->722653K(932096K), 1.5854120 secs] 
65558.803: [Full GC 815616K->727582K(932096K), 1.2067870 secs] 
65566.769: [Full GC 815615K->728443K(932096K), 1.2114200 secs] 
65570.652: [Full GC 815616K->730066K(932096K), 1.2135840 secs] 
65572.352: [Full GC 815616K->723875K(932096K), 1.4702710 secs] 
65577.304: [Full GC 815615K->727897K(932096K), 1.2087790 secs] 
65583.316: [Full GC 815615K->727540K(932096K), 1.2091610 secs] 
65590.292: [Full GC 815615K->728114K(932096K), 1.2074670 secs] 
65599.993: [Full GC 815615K->722369K(932096K), 1.2465300 secs] 
65616.109: [Full GC 815615K->728427K(932096K), 1.2092820 secs] 
65620.070: [Full GC 815615K->728823K(932096K), 1.2068140 secs] 
65626.774: [Full GC 815615K->728454K(932096K), 1.2046050 secs] 
65637.302: [Full GC 815615K->722224K(932096K), 1.4699560 secs] 
65639.319: [Full GC 815615K->728140K(932096K), 1.2258630 secs] 
65656.674: [Full GC 815615K->726831K(932096K), 1.2203520 secs] 
65667.239: [Full GC 815615K->727786K(932096K), 1.2212360 secs] 
65678.905: [Full GC 815615K->721629K(932096K), 1.4281870 secs] 
65686.655: [Full GC 815615K->728126K(932096K), 1.2147860 secs] 
65689.521: [Full GC 815615K->723848K(932096K), 1.2070410 secs] 
65697.409: [Full GC 815615K->727932K(932096K), 1.2111580 secs] 
65712.853: [Full GC 815615K->721999K(932096K), 1.4991350 secs] 
65719.399: [Full GC 815615K->727715K(932096K), 1.2149930 secs] 
65727.209: [Full GC 815615K->727355K(932096K), 1.2048690 secs] 
65728.726: [Full GC 815615K->730012K(932096K), 1.2185660 secs] 
65730.225: [Full GC 815615K->725299K(932096K), 1.4965130 secs] 
65732.111: [Full GC 815615K->728544K(932096K), 1.2107770 secs] 
65738.952: [Full GC 815615K->726932K(932096K), 1.2066580 secs] 

क्या यह मेरा ऐप लीक मेमोरी है या क्या यह मेरी कॉन्फ़िगरेशन है जिसे ठीक-ठीक किया जाना चाहिए? मैं निम्नलिखित सेटअप का उपयोग कर रहा हूँ:

CentOS release 5.2 (Final) x86_64 
Java JDK 1.6.06 64-bit 
JBoss 4.2.2.GA 
RAM: 4GB 
Swap Space: 2GB 
Processor: Intel(R) Xeon(R) CPU X3323 @ 2.50GHz 

निम्न आदेश jboss को चलाने के लिए प्रयोग किया जाता है:

java -Dprogram.name=run.sh -server -Xms256m -Xmx1024m -XX:PermSize=64m -XX:MaxPermSize=256m -verbose:gc -Xloggc:/data1/logs/jboss/GC.log -XX:+HeapDumpOnOutOfMemoryError -Dsun.rmi.dgc.client.gcInterval=3600000 -Dsun.rmi.dgc.server.gcInterval=3600000 -Dorg.apache.catalina.STRICT_SERVLET_COMPLIANCE=false -Djava.net.preferIPv4Stack=true -Djava.library.path=/usr/local/java/jboss-4.2.2.GA/bin/native -Djava.endorsed.dirs=/usr/local/java/jboss-4.2.2.GA/lib/endorsed -classpath /usr/local/java/jboss-4.2.2.GA/bin/run.jar:/usr/local/java/jdk1.6.0_06/lib/tools.jar org.jboss.Main -c default -b <IP_ADDRESS> -Djboss.messaging.ServerPeerID=1 

किसी भी मदद की बहुत ज्यादा appriciated किया जाएगा। इसके अलावा, भविष्य में जीसी/हीप डंप का विश्लेषण करने के तरीके पर कोई प्रकाश भी मेरे लिए एक बड़ी मदद होगी।

शुभकामनाओं सहित,
सुमित तनेजा

+4

+1। – Nishant

+0

@ जीसी लॉग के बजाय सुमित, हाइबरनेट कोड पोस्ट करें। –

+0

यह शायद आपकी समस्या का समाधान नहीं करेगा, लेकिन आपका जेडीके ** सख्त ** अपग्रेड की आवश्यकता है! –

उत्तर

3

4GB रैम के साथ चल रहा है करने के लिए -UseGCOverheadLimit और -Xmx1024m (जावा ढेर 1024M की अधिकतम राशि) का उपयोग कर जान बूझ कर नहीं हो सकता है: यदि आवश्यक हो, इस सुविधा विकल्प -XX जोड़कर निष्क्रिय किया जा सकता।

दूसरी तरफ, यह मुझे लगता है कि आपकी क्वेरी या तो null सीमा का उपयोग करने के कारण बहुत अधिक परिणाम लौट रही है, जो एक विस्तृत सूची में बदल जाती है।

आप

# jmap -dump:format=b,file=dump.hprof <pid> 

साथ जेंटलमैन कैडेट के बीच में एक ढेर स्नैपशॉट लेने और फिर ऊपर उल्लिखित Memory Analyzer का उपयोग करके शुरू कर सकता है। एक अच्छी तरह से लिखित प्रश्न के लिए

+0

जानकारी के लिए धन्यवाद, यह जांच लें और अपडेट करें। साथ ही, यह सुनिश्चित न करें कि '4 जीबी रैम के साथ चल रहा है और -Xmx1024m (जावा ढेर 1024 एम की अधिकतम मात्रा) का उपयोग करके जानबूझकर नहीं हो सकता है। मैंने जानबूझकर jboss चलाने के लिए -Xms और -Xmx झंडे जोड़े हैं। – Sumit

+0

@ सुमित: मेरा मतलब था - यदि आप उस सर्वर पर और कुछ नहीं चलाते हैं - तो आप JVM को और अधिक मेमोरी आवंटित कर सकते हैं, क्योंकि अन्य 3 जीबी व्यावहारिक रूप से कुछ भी नहीं कर पाएंगे। यदि सर्वर अन्य चीजें चलाता है, तो यह बिल्कुल ठीक है। –

+0

स्पष्टीकरण के लिए धन्यवाद। हां, सर्वर पर अन्य ऐप्स चल रहे हैं !! – Sumit

3

Eclipse मेमोरी विश्लेषक कहा जाता है के लिए एक महान उपकरण प्रदान करता है। यह ओओएम पर उत्पन्न होने वाले सटीक ढेर डंप का विश्लेषण कर सकता है। यह आपको बहुत कम चार्ट बनाने में मदद करता है जहां आपकी मेमोरी खपत का बड़ा हिस्सा है - आपका ऐप, जेबॉस, आपके सेटअप के अन्य हिस्सों - एक बहुत अच्छे स्तर तक।

यदि आप यहां अपना आउटपुट पेस्ट करते हैं तो हम आपकी समस्या की जांच जारी रख सकते हैं।

+0

त्वरित उत्तर के लिए धन्यवाद। मैं मैट और पोस्ट आउटपुट स्थापित करेंगे। इस बीच, जेबीओएस से हीप डंप भी पोस्ट करते हुए पूर्ण जीसी हो रहे थे। – Sumit

+0

सहमत हैं, अगर आपके पास ढेर डंप है तो MAT अविश्वसनीय रूप से उपयोगी है। – Jubal

0
Somewhere your code is creating temporary objects in an memory- less environment. 
Please look at your code (HibernateCommentaryDao.java) 

it is something with n+1 fetch 

Excessive GC Time and OutOfMemoryError

समानांतर कलेक्टर फेंक होगा एक OutOfMemoryError बहुत अधिक समय कचरा संग्रहण में खर्च किया जा रहा है यदि: यदि कुल समय से अधिक 98% कचरा संग्रहण में खर्च किया जाता है और कम से कम ढेर के 2% से अधिक बरामद किया गया है, OutOfMemoryError फेंक दिया जाएगा। यह सुविधा के लिए को कम या कोई प्रगति नहीं करते समय बहुत कम है, जबकि के लिए चलने से अनुप्रयोगों को रोकने के लिए डिज़ाइन किया गया है। कमांड लाइन

+0

इस पर ध्यान देने के लिए धन्यवाद। जैसा कि आपने अनुरोध किया था, कोड में कोड जोड़ा गया (माफ करना कोड बहुत लंबा है इसलिए यहां पोस्ट नहीं किया जा सका!) – Sumit