An introduction to java stack traces

StackTraces
ByCalvinAustin
July1998

It'sthenightbeforeyourproductrelease.Yourunyourfinaltestsandthenithappens--yougetaJavastacktrace.YoulookthroughyourJavaprogrammingbooks,butthisseemstobeanareathat'smissing!Wellnoneedtopanic,justfollowthesimplestepssuggestedhereandyou'llbehomebeforemidnight!ThisarticleshowsyoustepbystephowtorecognizeandcollectthecluesinastacktracetosolveyourJavasoftwareproblems.

WhatisaJavastacktrace?AJavastacktraceisauser-friendlysnapshotofthethreadsandmonitorsinaJava1VirtualMachine(JVM).Dependingonhowcomplexyourapplicationorappletis,astacktracecanrangefromfiftylinestothousandsoflinesofdiagnostics.

However,regardlessofthesizeofthestacktracethereareafewkeythingsthatanyonecanfindtohelpdiagnosemostJavasoftwareproblems,whetheryouareaJavaprogrammingexpertorverynewtotheJavaplatform.

HowareJavaStackTracesGenerated?

TherearethreepopularwaystogenerateaJavastacktrace:sendingasignaltotheJavaVirtualMachine;theJavaVirtualMachinegeneratesastacktraceforyou;orusingdebuggingtoolsorJavaAPIcalls.

SendingasignaltotheJavaVirtualMachine

OnUNIXplatformsyoucansendasignaltoaprogrambyusingthekillcommand.Thisisthequitsignal,whichishandledbytheJVM.Forexample,onSolarisyoucanusethecommand

kill-QUITprocess_id

,where

process_id

istheprocessnumberofyourJavaprogram.

Alternativelyyoucanenterthekeysequence

<ctrl>/

inthewindowwheretheJavaprogramwasstarted.SendingthissignalinstructsasignalhandlerintheJVM,torecursivelyprintoutalltheinformationonthethreadsandmonitorsinsidetheJVM.

TogenerateastacktraceonWindows95,orWindowsNTplatforms,enterthekeysequence

<ctrl><break>

inthewindowwheretheJavaprogramisrunning,orclicktheClosebuttononthewindow.

TheJavaVirtualMachinegeneratesastacktraceforyou

IftheJVMexperiencedaninternalerror,forexampleasegmentationviolationoranillegalpagefault,itwillcallitsownsignalhandlertoprintoutthethreadsandmonitorsinformation.

UsingdebuggingtoolsorJavaAPIcalls

YoucangenerateapartialJavastacktrace,whichinthiscaseisonlythethreadsinformation,byusingthe

Thread.dumpStack

method,orthe

printStackTrace

methodoftheThrowableclass.Youcanalsoobtainsimilarinformationbyenteringthecommand"

where

"insidetheJavadebugger.

Ifyouaresuccessfulatgeneratingastacktraceyoushouldseesomethinglikethis:$SIGQUIT3*quit
si_signo[3]:SIGQUIT3*quit
si_errno[0]:Error0
si_code[0]:SI_USER[pid:11927,uid:26432]
stackbase=EE292000,stackpointer=EE291878

Fullthreaddump:
"Thread-5"(TID:0xee703b78,sys_thread_t:0xee261db8,state:R)prio=5
mythread.stopper(exec3.java:10)
mythread.run(exec3.java:16)
"Thread-4"(TID:0xee703bb8,sys_thread_t:0xee291db8,state:R)prio=5*currentthread*
mythread.stopper(exec3.java:10)
mythread.run(exec3.java:16)
"Finalizerthread"(TID:0xee700220,sys_thread_t:0xee2c1db8,state:R)prio=1
"AsyncGarbageCollector"(TID:0xee700268,sys_thread_t:0xee2f1db8,state:R)prio=1
"Idlethread"(TID:0xee7002b0,sys_thread_t:0xee3c1db8,state:R)prio=0
"Clock"(TID:0xee700088,sys_thread_t:0xee3f1db8,state:CW)prio=12
"main"(TID:0xee7000b0,sys_thread_t:0x693a0,state:CW)prio=5
exec3.main(exec3.java:32)
MonitorCacheDump:
mythread@EE703BB8/EE74E190:owner"Thread-4"(0xee291db8,1entry)
mythread@EE703B78/EE74E270:owner"Thread-5"(0xee261db8,1entry)
<unknownkey>(0x693a0):<unowned>
Waitingtobenotified:
"main"(0x693a0)
RegisteredMonitorDump:
Threadqueuelock:<unowned>
Nameandtypehashtablelock:<unowned>
Stringinternlock:<unowned>
JNIpinninglock:<unowned>
JNIglobalreferencelock:<unowned>
BinClasslock:<unowned>
Classloadinglock:<unowned>
Javastacklock:<unowned>
Coderewritelock:<unowned>
Heaplock:<unowned>
Hasfinalizationqueuelock:<unowned>
Finalizemequeuelock:<unowned>
MonitorIOlock:<unowned>
Childdeathmonitor:<unowned>
Eventmonitor:<unowned>
I/Omonitor:<unowned>
Alarmmonitor:<unowned>
Waitingtobenotified:
"Clock"(0xee3f1db8)
Sbrklock:<unowned>
Monitorregistry:owner"Thread-4"(0xee291db8,1entry)
ThreadAlarmQ:
sys_thread_t0x693a0[Timeoutin9997374ms]

WhataretheFirstThingstoLookfor?

Byfollowingthenextthreestepsyoumightfindthesolutiontotheapplication'sproblemwithoutanymoreanalysis.However,ifyoudon't,theevidenceyou'llgainfromthisexerciseisvitaltoanyfurtherinvestigation.

Findingthecurrentthread

YounowhaveaJavastacktrace.Thefirstpieceofinformationyouneedtolookforisthecurrentthread.Intheorythecurrentthreadshouldbethelastthreadthatwasrunningwhenthesnapshotwastaken.IfyouhaveseenaJavastacktracebeforeyoumayhavenoticedthatoftenthecurrentthreadislabeled*currentthread*nexttotheappropriatethread.

Isthatthecurrentthreadyouask?Mostofthetimeyes,butunfortunatelythisisonlyagoodguessbythesignalhandler.Sometimesthesignalhandlerwillbemarkedasthecurrentthread,whichdoesn'thelpyourdiagnosisatall!Andonsomeplatformsnoneofthethreadswillbemarkedasthecurrentthread!Butdon'tdespair,moreevidenceaboutwhichthreadisthecurrentthreadisexplainedinthesection,"ExaminingMonitors".

Note:Ifyouseethelabel

CompiledCode

nexttothecurrentthreadthenthisstacktracecamefromaJVMusingtheJITcompiler.IfpossiblegenerateanotherstacktracewithouttheJITenabledusingthe

-nojit

parametertotheJVM.

Runnablethreads

NextyouneedtotrackdownallthethreadsthathaveastateofR,whichstandsforRunnable.ThreadsintheRstatewererunning,orwerereadytorunthenexttimethethreadswerescheduled.Makeanoteofthese,becausetheycouldindicatewhereyourproblemlies.

Thereismoreevidenceaboutwhichthreadisthecurrentthreadexplainedinthesection,"ExaminingMonitors".

Corefiles

IftheJVMgeneratedthestacktracebecauseofaninternalerrorthensomenativecodeinyourownapplication,ortheJVMwasprobablytoblame.IfyouareusingUNIX,andyoufindacorefile,runthefollowingcommandtofindoutwhichJDKsoftwareitcamefrom:

stringscore|grepJAVA_HOME

IntheJDK1.2softwarerelease,threadsthatcalledmethodsresultinginacalltonativecodeareindicatedinthestacktrace.

WhichSoftwareReleaseandwhichPlatformGeneratedtheStackTrace?

Wouldn'titbeeasierifthestacktracecontainedaJDKversionstring?Well,thereisarequestforaversionstringtobeincludedinanystacktraceinbugnumber4047300.Whenthisrequestisimplementeditwilleliminatetheneedforthenextsection!

However,withoutaversionstringyoucantakeaprettygoodguessaswhichreleasethisstacktracecamefrom.Obviouslyifyougeneratedthestacktraceyourselfthisshouldn'tbemuchofanissue,butyoumayseeastacktracepostedonanewsgrouporinanemailarticle.

Herearesomehintstohelpinyourdetectivework:

FirstidentifywheretheRegisteredMonitorDumpsectionisinthestacktrace:Ifyouseea

utf8hashtablelock

intheRegisteredMonitorDumpthenthisisaJDK1.2stacktrace.Ifyouseea

JNIpinninglock

andno

utf8hashlock

thenthisisaJDK1.1+release.IfneitheroftheseappearsintheRegisteredMonitorDumpthenitisprobablyaJDK1.0.2release.

Whatplatformdidthestacktracecomefrom?

YoucanalsofindoutifthestacktracecamefromaWindows95,anNT,oraUNIXmachinebylookingforanywaitingthreads.OnaUNIXmachinethewaitingthreadsarenamedexplicitly.OnaWindows95,orNTmachineonlyacountofthewaitingthreadsisdisplayed:

Windows95/NT:

Finalizemequeuelock:<unowned>Writer:1UNIX:Finalizemequeuelock:<unowned>

waitingtobenotified"FinalizerThread"

Determiningwhichthreadpackagewasused.

Windows95andWindowsNTJavaVirtualMachinesarebydefaultnativethreadJVMs.UNIXJVMsarebydefaultgreenthreadJVMs,theyuseapseudothreadimplementation.TomakeyourJVMusenativethreadsyouneedtosupplythe

-native

parameter,forexample,

java-nativeMyClass

.

Byverifyingtheexistenceofan

Alarmmonitor

inthestacktraceoutputyoucanidentifythatthisstacktracecamefromagreenthreadsJVM.

DeterminingtheThreadStates

YouwillseemanydifferentthreadsinmanydifferentstatesinasnapshotfromaJVMstacktrace.Thekeyusedis:

R	Runningorrunnablethread
S	Suspendedthread
CW	Threadwaitingonaconditionvariable
MW	Threadwaitingonamonitorlock
MS	Threadsuspendedwaitingonamonitorlock

NormallyonlythreadsinR,S,CWorMWshouldappearinthestacktrace.IfyouseeathreadinstateMS,reportittoSunMicrosystems,viatheBugParadeasthereisagoodchanceitisabug,becausemostofthetimeathreadinMonitorWaitstatewillappearintheSstatewhenitissuspended.Monitors(coveredinthenextsection)areusedtomanageaccesstocodethatshouldonlyberunbyasinglethreadatatime.

ExaminingMonitors

Thisbringsustotheotherpartofthestacktrace:themonitordump.Ifyouconsiderthatthethreadssectionofastacktraceidentifiesthemultithreadedpartofyourapplicationthenthemonitorssectionrepresentsthepartsofyourapplicationthataresinglethreaded.

Itmaybeeasiertoimagineamonitorasacarwash.Inmostcarwashes,onlyonecarcanbeinthewashatatime.InyourJavacodeonlyonethreadcanhavethelocktoasynchronizedpieceofcodeatatime.Alltheotherthreadsqueueuptoenterthesynchronizedcodejustascarsqueueuptoenterthecarwash.

Amonitorcanbethoughtofasalockonanobject,andeveryobjecthasamonitor.Whenyougenerateastacktrace,monitorsarelistedasbeingeitherregisteredornotregistered.Inthemajorityofcasestheseregisteredmonitors,orsystemmonitors,shouldn'tbethecauseofyoursoftwareproblems.Butithelpstobeabletounderstandandrecognizethem.Thefollowingtabledescribesthecommonregisteredmonitors:

Threadqueuelock	Protectsthequeueofactivethreads.
Nameandtypehashtablelock	ProtectstheJVMhashtablesofconstantsandtheirtypes.
Stringinternlock	Locksthehashtableofdefined Stringsthatwereloadedfromtheclassconstantpool.
JNIpinninglock	Protectsblockcopiesofarraystonativemethodcode.
JNIglobalreferencelock	Lockstheglobalreferencetablewhichholdsvaluesthatneedtobeexplicitlyfreed,andwilloutlivethelifetimeofthenativemethodcall.
BinClasslock	Locksaccesstotheloadedandresolvedclasseslist.
Classloadinglock	Ensuresonlyonethreadloadsaclassatatime.
Javastacklock	Protectsthefreestacksegmentslist.
Coderewritelock	Protectscodewhenanoptimizationisattempted.
Heaplock	ProtectstheJavaheapduringheapmemorymanagement
Hasfinalizationqueuelock	Protectsthelistofqueuelockobjectsthathavebeengarbage-collected,anddeemedtoneedfinalization.TheyarecopiedtotheFinalizemequeue.
Finalizemequeuelock	Protectsalistofobjectsthatcanbefinalizedatleisure.
MonitorIOlock	ProtectsphysicalI/Oforexample, openandread.

Themonitorregistryitselfisprotectedbyamonitor.Thismeansthatthethreadthatownsthelockisthelastthreadtouseamonitor.It'sverylikelythatthisthreadmayalsobethecurrentthread.

Becauseonlyonethreadcanenterasynchronizedblockatatime,otherthreadsqueueupatthestartofthesynchronizedcodeandappearasthreadstateMW.Inthemonitorcachedumptheywillbedenotedas"waitingtoenter"threads.Inusercodeamonitoriscalledintoactionwhereverasynchronizedblockormethodisused.

Anycodewaitingonanobjectorevent,thatisawaitmethod,alsohastobeinsideasynchronizedblock.Howeveroncethewaitmethodiscalled,thelockonthesynchronizedobjectisgivenup.

Whenthethreadinthewaitstateisnotifiedofaneventtotheobject,ithastocompeteforexclusiveaccesstothatobject,andithastoobtainthemonitor.Evenwhenathreadhassenta"notifyevent"tothewaitingthreads,noneofthewaitingthreadscanactuallygaincontrolofthemonitorlockuntilthenotifyingthreadhasleftitssynchronizedcodeblock.

Youwillsee"Waitingtobenotified"forthreadsatthewaitmethod

PuttingtheStepsintoPractice

Considerareallifeproblem:Bug4098756forexample.YoucanfinddetailsonthisbuginJDCBugParade.ThisbugdocumentsaproblemthatoccurredwhenusingaChoiceComponentonWindows95.

WhentheuserselectedoneofthechoicesfromtheChoiceComponentusingthemouse,everythingwasfine.HoweverwhentheusertriedtouseanarrowkeytomoveupordownthelistofchoicestheJavaapplicationfroze.

FortunatelythisproblemwasreproducibleandtherewasaJavastacktracetohelptrackdowntheproblem.Thefullstacktraceisinthebugreportpage,butyouonlyneedtofocusontwokeythreads,forexample:

"AWT-Windows"(TID:0xf54b70,sys_thread_t:0x875a80,Win32ID:0x67,

state:MW)prio=5

java.awt.Choice.select(Choice.java:293)

sun.awt.windows.WChoicePeer.handleAction(WChoicePeer.java:86)

"AWT-EventQueue-0"(TID:0xf54a98,sys_thread_t:0x875c20,

Win32ID:0x8f,state:R)prio=5

java.awt.Choice.remove(Choice.java:228)

java.awt.Choice.removeAll(Choice.java:246)

The

AWT-EventQueue-0

threadisinarunnablestateinsidethe

remove

method.

Remove

issynchronizedsothatexplainswhytheotherthread,

AWT-Windows

,cannotentertheselectmethod.The

AWT-Windows

threadisinstateMW,monitorwait.

However,ifyoukeeptakingstacktracesthissituationdoesnotchange,andtheGUIappearstohavefrozen.Thisindicatesthattheremovecallneverreturned.ByfollowingthecodepathtotheChoicePeerclass,youcanseethatthisismakinganativeMFCcallthatdoesnotreturn.That'swheretherealproblemliesandisabugintheJavacoreclasses.Theuser'scodewasOK.

Expert'sChecklist

ThiscoversthetheoryaboutJavastacktraces,andyoushouldnowknowwhattolookfornexttimeyouseeone.Tosaveyourselftime,besuretomakefulluseoftheJDCbugsearchtoseeiftheproblemyouarehavinghasalreadybeenreported.

Tosummarize,herearethestepstotakewhenyounextcomeacrossaproblemJavaprogram:

Forhanging,deadlockedorfrozenprograms:Ifyouthinkyourprogramishanging,generateastacktraceandexaminethethreadsinstatesMWorCW.Iftheprogramisdeadlockedthensomeofthesystemthreadswillprobablyshowupasthecurrentthreads,becausethereisnothingelsefortheJVMtodo.

Forcrashed,abortedprograms:OnUNIXlookforacorefile.Youcananalyzethisfileinanativedebuggingtoolsuchas

gdb

or

dbx

.Lookforthreadsthathavecallednativemethods.BecauseJavatechnologyusesasafememorymodel,anycorruptionprobablyoccurredinthenativecode.RememberthattheJVMalsousesnativecode,soitmaynotnecessarilybeabuginyourapplication.

Forbusyprograms:Thebestcourseofactionyoucantakeforbusyprogramsistogeneratefrequentstacktraces.Thiswillnarrowdownthecodepaththatiscausingtheerrors,andyoucanthenstartyourinvestigationfromthere.

GoodLuckandHappyDebugging



CalvinAustinisasoftwareengineerontheJavaDeveloperConnectionteam.Thisarticleisbasedonapresentationhedeliveredatthe1998JavaOneSMDeveloperConference.

_______
1Asusedonthiswebsite,theterms"Javavirtualmachine"or"JVM"meanavirtualmachinefortheJavaplatform.