From e7cfee8beb332e1112df08b0dc9cbee76c41eb9e Mon Sep 17 00:00:00 2001 From: Ben Gamari Date: Wed, 13 Mar 2019 09:52:26 -0400 Subject: [PATCH 1/4] Add support for nonmoving GC events --- include/EventLogFormat.h | 10 +++++++++- src/GHC/RTS/EventTypes.hs | 10 ++++++++++ src/GHC/RTS/Events.hs | 16 ++++++++++++++++ src/GHC/RTS/Events/Binary.hs | 31 +++++++++++++++++++++++++++++++ 4 files changed, 66 insertions(+), 1 deletion(-) diff --git a/include/EventLogFormat.h b/include/EventLogFormat.h index af80518..0f55389 100644 --- a/include/EventLogFormat.h +++ b/include/EventLogFormat.h @@ -202,12 +202,20 @@ #define EVENT_USER_BINARY_MSG 181 +#define EVENT_CONC_MARK_BEGIN 200 +#define EVENT_CONC_MARK_END 201 +#define EVENT_CONC_SYNC_BEGIN 202 +#define EVENT_CONC_SYNC_END 203 +#define EVENT_CONC_SWEEP_BEGIN 204 +#define EVENT_CONC_SWEEP_END 205 +#define EVENT_CONC_UPD_REM_SET_FLUSH 206 + /* * The highest event code +1 that ghc itself emits. Note that some event * ranges higher than this are reserved but not currently emitted by ghc. * This must match the size of the EventDesc[] array in EventLog.c */ -#define NUM_GHC_EVENT_TAGS 182 +#define NUM_GHC_EVENT_TAGS 207 /* DEPRECATED EVENTS: */ diff --git a/src/GHC/RTS/EventTypes.hs b/src/GHC/RTS/EventTypes.hs index f2b1508..2ebc5a6 100644 --- a/src/GHC/RTS/EventTypes.hs +++ b/src/GHC/RTS/EventTypes.hs @@ -431,6 +431,16 @@ data EventInfo | UserBinaryMessage { payload :: !B.ByteString } + + | ConcMarkBegin + | ConcMarkEnd { concMarkedObjectCount :: !Word32 + } + | ConcSyncBegin + | ConcSyncEnd + | ConcSweepBegin + | ConcSweepEnd + | ConcUpdRemSetFlush { cap :: {-# UNPACK #-}!Int + } deriving Show {- [Note: Stop status in GHC-7.8.2] diff --git a/src/GHC/RTS/Events.hs b/src/GHC/RTS/Events.hs index 35efba4..ef8e89b 100644 --- a/src/GHC/RTS/Events.hs +++ b/src/GHC/RTS/Events.hs @@ -492,6 +492,22 @@ buildEventInfo spec' = UserBinaryMessage {..} -> "binary message " <> TB.fromText (replaceUnprintableWith '.' payload) + ConcMarkBegin -> + "concurrent mark began" + ConcMarkEnd {..} -> + "concurrent mark ended: " + <> "marked " <> TB.decimal concMarkedObjectCount <> " objects" + ConcSyncBegin -> + "post-mark synchronization began" + ConcSyncEnd -> + "post-mark synchronization ended" + ConcSweepBegin -> + "concurrent sweep began" + ConcSweepEnd -> + "concurrent sweep ended" + ConcUpdRemSetFlush {..} -> + "update remembered set flushed by " <> TB.decimal cap + -- | Replace unprintable bytes in the message with the replacement character replaceUnprintableWith :: Char -- ^ Replacement character diff --git a/src/GHC/RTS/Events/Binary.hs b/src/GHC/RTS/Events/Binary.hs index 637e1ee..eda74c6 100644 --- a/src/GHC/RTS/Events/Binary.hs +++ b/src/GHC/RTS/Events/Binary.hs @@ -317,6 +317,20 @@ standardParsers = [ str <- getText (num - sz_tid) return ThreadLabel{ thread = tid , threadlabel = str } + )), + + (simpleEvent EVENT_CONC_MARK_BEGIN ConcMarkBegin), + (FixedSizeParser EVENT_CONC_MARK_END 4 (do -- (marked_object_count) + num <- get :: Get Word32 + return ConcMarkEnd{ concMarkedObjectCount = num } + )), + (simpleEvent EVENT_CONC_SYNC_BEGIN ConcSyncBegin), + (simpleEvent EVENT_CONC_SYNC_END ConcSyncEnd), + (simpleEvent EVENT_CONC_SWEEP_BEGIN ConcSweepBegin), + (simpleEvent EVENT_CONC_SWEEP_END ConcSweepEnd), + (FixedSizeParser EVENT_CONC_UPD_REM_SET_FLUSH sz_cap (do -- (cap) + cap <- get :: Get CapNo + return ConcUpdRemSetFlush{ cap = fromIntegral cap } )) ] @@ -1002,6 +1016,13 @@ eventTypeNum e = case e of ProfSampleCostCentre {} -> EVENT_PROF_SAMPLE_COST_CENTRE ProfBegin {} -> EVENT_PROF_BEGIN UserBinaryMessage {} -> EVENT_USER_BINARY_MSG + ConcMarkBegin {} -> EVENT_CONC_MARK_BEGIN + ConcMarkEnd {} -> EVENT_CONC_MARK_END + ConcSyncBegin {} -> EVENT_CONC_SYNC_BEGIN + ConcSyncEnd {} -> EVENT_CONC_SYNC_END + ConcSweepBegin {} -> EVENT_CONC_SWEEP_BEGIN + ConcSweepEnd {} -> EVENT_CONC_SWEEP_END + ConcUpdRemSetFlush {} -> EVENT_CONC_UPD_REM_SET_FLUSH nEVENT_PERF_NAME, nEVENT_PERF_COUNTER, nEVENT_PERF_TRACEPOINT :: EventTypeNum nEVENT_PERF_NAME = EVENT_PERF_NAME @@ -1427,3 +1448,13 @@ putEventSpec ProfBegin {..} = do putEventSpec UserBinaryMessage {..} = do putE (fromIntegral (B.length payload) :: Word16) putByteString payload + +putEventSpec ConcMarkBegin = return () +putEventSpec ConcMarkEnd {..} = do + putE concMarkedObjectCount +putEventSpec ConcSyncBegin = return () +putEventSpec ConcSyncEnd = return () +putEventSpec ConcSweepBegin = return () +putEventSpec ConcSweepEnd = return () +putEventSpec ConcUpdRemSetFlush {..} = do + putCap cap From 1f6a50b0ba946b052699cab599ac8c796ae319d7 Mon Sep 17 00:00:00 2001 From: Ben Gamari Date: Mon, 15 Apr 2019 16:54:31 -0400 Subject: [PATCH 2/4] Add support for EVENT_NONMOVING_HEAP_CENSUS --- include/EventLogFormat.h | 3 ++- src/GHC/RTS/EventTypes.hs | 6 ++++++ src/GHC/RTS/Events.hs | 5 +++++ src/GHC/RTS/Events/Binary.hs | 13 +++++++++++++ 4 files changed, 26 insertions(+), 1 deletion(-) diff --git a/include/EventLogFormat.h b/include/EventLogFormat.h index 0f55389..a571ffa 100644 --- a/include/EventLogFormat.h +++ b/include/EventLogFormat.h @@ -209,13 +209,14 @@ #define EVENT_CONC_SWEEP_BEGIN 204 #define EVENT_CONC_SWEEP_END 205 #define EVENT_CONC_UPD_REM_SET_FLUSH 206 +#define EVENT_NONMOVING_HEAP_CENSUS 207 /* * The highest event code +1 that ghc itself emits. Note that some event * ranges higher than this are reserved but not currently emitted by ghc. * This must match the size of the EventDesc[] array in EventLog.c */ -#define NUM_GHC_EVENT_TAGS 207 +#define NUM_GHC_EVENT_TAGS 208 /* DEPRECATED EVENTS: */ diff --git a/src/GHC/RTS/EventTypes.hs b/src/GHC/RTS/EventTypes.hs index 2ebc5a6..38067d2 100644 --- a/src/GHC/RTS/EventTypes.hs +++ b/src/GHC/RTS/EventTypes.hs @@ -441,6 +441,12 @@ data EventInfo | ConcSweepEnd | ConcUpdRemSetFlush { cap :: {-# UNPACK #-}!Int } + | NonmovingHeapCensus + { nonmovingCensusBlkSize :: !Word8 + , nonmovingCensusActiveSegs :: !Word32 + , nonmovingCensusFilledSegs :: !Word32 + , nonmovingCensusLiveBlocks :: !Word32 + } deriving Show {- [Note: Stop status in GHC-7.8.2] diff --git a/src/GHC/RTS/Events.hs b/src/GHC/RTS/Events.hs index ef8e89b..630e255 100644 --- a/src/GHC/RTS/Events.hs +++ b/src/GHC/RTS/Events.hs @@ -507,6 +507,11 @@ buildEventInfo spec' = "concurrent sweep ended" ConcUpdRemSetFlush {..} -> "update remembered set flushed by " <> TB.decimal cap + NonmovingHeapCensus {..} -> + "nonmoving heap census " <> TB.decimal (2^nonmovingCensusBlkSize :: Int) + <> ": " <> TB.decimal nonmovingCensusActiveSegs <> " active segments" + <> ", " <> TB.decimal nonmovingCensusFilledSegs <> " filled segments" + <> ", " <> TB.decimal nonmovingCensusLiveBlocks <> " live blocks" -- | Replace unprintable bytes in the message with the replacement character replaceUnprintableWith diff --git a/src/GHC/RTS/Events/Binary.hs b/src/GHC/RTS/Events/Binary.hs index eda74c6..07910b1 100644 --- a/src/GHC/RTS/Events/Binary.hs +++ b/src/GHC/RTS/Events/Binary.hs @@ -331,6 +331,13 @@ standardParsers = [ (FixedSizeParser EVENT_CONC_UPD_REM_SET_FLUSH sz_cap (do -- (cap) cap <- get :: Get CapNo return ConcUpdRemSetFlush{ cap = fromIntegral cap } + )), + (FixedSizeParser EVENT_NONMOVING_HEAP_CENSUS 13 (do -- (blk_size, active_segs, filled_segs, live_blks) + nonmovingCensusBlkSize <- get :: Get Word8 + nonmovingCensusActiveSegs <- get :: Get Word32 + nonmovingCensusFilledSegs <- get :: Get Word32 + nonmovingCensusLiveBlocks <- get :: Get Word32 + return NonmovingHeapCensus{..} )) ] @@ -1023,6 +1030,7 @@ eventTypeNum e = case e of ConcSweepBegin {} -> EVENT_CONC_SWEEP_BEGIN ConcSweepEnd {} -> EVENT_CONC_SWEEP_END ConcUpdRemSetFlush {} -> EVENT_CONC_UPD_REM_SET_FLUSH + NonmovingHeapCensus {} -> EVENT_NONMOVING_HEAP_CENSUS nEVENT_PERF_NAME, nEVENT_PERF_COUNTER, nEVENT_PERF_TRACEPOINT :: EventTypeNum nEVENT_PERF_NAME = EVENT_PERF_NAME @@ -1458,3 +1466,8 @@ putEventSpec ConcSweepBegin = return () putEventSpec ConcSweepEnd = return () putEventSpec ConcUpdRemSetFlush {..} = do putCap cap +putEventSpec NonmovingHeapCensus {..} = do + putE nonmovingCensusBlkSize + putE nonmovingCensusActiveSegs + putE nonmovingCensusFilledSegs + putE nonmovingCensusLiveBlocks From 3591d91a9769e947adefc502276426082cbc4e11 Mon Sep 17 00:00:00 2001 From: Ben Gamari Date: Wed, 22 Apr 2020 14:02:25 -0400 Subject: [PATCH 3/4] Add test for nonmoving gc events --- ghc-events.cabal | 2 + test/Utils.hs | 1 + test/nonmoving-gc.eventlog | Bin 0 -> 3212 bytes test/nonmoving-gc.eventlog.reference | 95 +++++++++++++++++++++++++++ 4 files changed, 98 insertions(+) create mode 100644 test/nonmoving-gc.eventlog create mode 100644 test/nonmoving-gc.eventlog.reference diff --git a/ghc-events.cabal b/ghc-events.cabal index d773c86..ae1d275 100644 --- a/ghc-events.cabal +++ b/ghc-events.cabal @@ -36,6 +36,8 @@ extra-source-files: include/EventLogFormat.h test/queens-ghc-7.0.2.eventlog.reference test/mandelbrot-mmc-2011-06-14.eventlog test/mandelbrot-mmc-2011-06-14.eventlog.reference + test/nonmoving-gc.eventlog + test/nonmoving-gc.eventlog.reference test/parallelTest.eventlog test/parallelTest.eventlog.reference test/pre77stop.eventlog diff --git a/test/Utils.hs b/test/Utils.hs index 975685c..de5a0cd 100644 --- a/test/Utils.hs +++ b/test/Utils.hs @@ -5,6 +5,7 @@ files = map ("test/"++) [ "queens-ghc-6.12.1.eventlog" , "queens-ghc-7.0.2.eventlog" , "mandelbrot-mmc-2011-06-14.eventlog" + , "nonmoving-gc.eventlog" , "parallelTest.eventlog" , "pre77stop.eventlog", "782stop.eventlog", "783stop.eventlog" , "sleep.h.eventlog" diff --git a/test/nonmoving-gc.eventlog b/test/nonmoving-gc.eventlog new file mode 100644 index 0000000000000000000000000000000000000000..9998a57fff0121fbdc0974ddc4772cd3be46e817 GIT binary patch literal 3212 zcmai0OKcoP5bfPW!Rv4QS^wfs8xxY?tg|L0IEgsm4^E`m1lv(Ah^Tj_cXzb&qi5ER zt#Co&0w>_W2`T&|?jSf}i3`CYZ~+e7IUp{+AwZa_n(@j#yNNCD&UV*(udA!8s;6wK zLRp3d_-F8U7(Q*YN{UeOunbQVXJshi1Ar6(nwP6?BWs#91Gr@+^!!HVLqzUaC0VYj zt}6<*)btOtBQS1Xv`XqB9yAf6?S`nxYQt4BD2Pr76UpwyAESw_XpVYRKtfgmX5cki5HdUJc>9>A?sOQUE!{9Bp0s9*Q5$8&(*viAzbG*T<#AyC(x72qN7OE?XckEG_Q;XMpA#jvLguX-VLo3a!>l(NGmgr37z zJp&q|end|bp>wvXC{KtISetq%&Jw6s1KAeTiYY>&Ir$936Yaf>D+i$nErVlMbD(My ziFJ-$1Y{d@1;PaY)idur3bWyr4c90`Ay|O~r03_tvdlr7vFqCIv#bjUEvq7^aHBp` zr)d+dWOkyv0T-yXsS8vv5#6LdqnR&KInR@-Wl*C8p~CyI0s0eiXmB1{Vq%Al(4SI0PBeD^WWmD5 z>6a}-*ryuNKO@&hR-uNm)nOd<-GsuZXh(3D-0Q0?C^$BNJ+cP7a3xv;ov#3hASE%(bJ&}-@*-Dm?CpM$~QllFL>HdarqKA_qX_s%xa#u95B zK)O$)-nzAdbt!$c)hgx(LiQx&>v0dLa}8hjpB($W0RPf#e7cno|ReXoignwjh zFwQQ)_2;c&eo3{ty9PI@DW|>dQzH;Y{-=?acf5kYCSmvE?>B(MNU}MqDmxrR6 zD@$xRn)!K)4dJha%d@%Z$*KJ06jxzz6W)Grni84-8;Nj#ycRJg&nybdWm9=J0dEg1 zXXk{=a<}0A!+VLP&fR{GjZt#q_T5?_;Ou-Qv8B>s$KYSTW+RJ`W{6du7Y5XO_OoKy z^OxRaCu*;)n3)Gt=Kf=2HOhWX%@fN0)N^m0X7^|V+oM~I4Q3f-ZtDJDDHb7i-kymN z>ApW9+9ONRe7f)Nf8+W76sB#APxl}BWpBRuMVhCiP7h4v8D(mEF!e5@OiT}Ew|95{ E2l%K(r~m)} literal 0 HcmV?d00001 diff --git a/test/nonmoving-gc.eventlog.reference b/test/nonmoving-gc.eventlog.reference new file mode 100644 index 0000000..8c73e2d --- /dev/null +++ b/test/nonmoving-gc.eventlog.reference @@ -0,0 +1,95 @@ +Event Types: +0: Create thread (size 4) +1: Run thread (size 4) +2: Stop thread (size 10) +3: Thread runnable (size 4) +4: Migrate thread (size 6) +8: Wakeup thread (size 6) +9: Starting GC (size 0) +10: Finished GC (size 0) +11: Request sequential GC (size 0) +12: Request parallel GC (size 0) +15: Create spark thread (size 4) +16: Log message (size variable) +18: Block marker (size 14) +19: User message (size variable) +20: GC idle (size 0) +21: GC working (size 0) +22: GC done (size 0) +25: Create capability set (size 6) +26: Delete capability set (size 4) +27: Add capability to capability set (size 6) +28: Remove capability from capability set (size 6) +29: RTS name and version (size variable) +30: Program arguments (size variable) +31: Program environment variables (size variable) +32: Process ID (size 8) +33: Parent process ID (size 8) +34: Spark counters (size 56) +35: Spark create (size 0) +36: Spark dud (size 0) +37: Spark overflow (size 0) +38: Spark run (size 0) +39: Spark steal (size 2) +40: Spark fizzle (size 0) +41: Spark GC (size 0) +43: Wall clock time (size 16) +44: Thread label (size variable) +45: Create capability (size 2) +46: Delete capability (size 2) +47: Disable capability (size 2) +48: Enable capability (size 2) +49: Total heap mem ever allocated (size 12) +50: Current heap size (size 12) +51: Current heap live data (size 12) +52: Heap static parameters (size 38) +53: GC statistics (size 58) +54: Synchronise stop-the-world GC (size 0) +55: Task create (size 18) +56: Task migrate (size 12) +57: Task delete (size 8) +58: User marker (size variable) +59: Empty event for bug #9003 (size 0) +160: Start of heap profile (size variable) +161: Cost center definition (size variable) +162: Start of heap profile sample (size 8) +163: Heap profile cost-centre sample (size variable) +164: Heap profile string sample (size variable) +165: End of heap profile sample (size 8) +166: Start of heap profile (biographical) sample (size 16) +167: Time profile cost-centre stack (size variable) +168: Start of a time profile (size 8) +181: User binary message (size variable) +200: Begin concurrent mark phase (size 0) +201: End concurrent mark phase (size 4) +202: Begin concurrent GC synchronisation (size 0) +203: End concurrent GC synchronisation (size 0) +204: Begin concurrent sweep (size 0) +205: End concurrent sweep (size 0) +206: Update remembered set flushed (size 2) +207: Nonmoving heap census (size 13) + +Events: +620636: capset 1: wall clock time 1587578331s 829795000ns (unix epoch) +627395: capset 0: pid 20807 +636419: capset 0: parent pid 18766 +644544: capset 0: RTS version "GHC-8.10.1 rts_thr_debug" +649853: capset 0: args: ["./Main","10","+RTS","-l-an","-xn"] +20282519: Starting nonmoving GC preparation +20305849: Marking roots for nonmoving GC +20331402: Finished marking roots for nonmoving GC +20333822: Finished nonmoving GC preparation +20810540: concurrent mark began +30089152: concurrent mark ended: marked 6677 objects +30210049: post-mark synchronization began +32582336: cap 0: update remembered set flushed by 0 +32608578: concurrent mark began +35122177: concurrent mark ended: marked 7758 objects +35126012: concurrent mark began +35127755: concurrent mark ended: marked 1 objects +35129046: concurrent mark began +35129935: concurrent mark ended: marked 1 objects +35203888: post-mark synchronization ended +35258771: concurrent sweep began +35263947: concurrent sweep ended + From 149b9ca093d828f8e5a3ea88069ae36af2d7e6e1 Mon Sep 17 00:00:00 2001 From: Ben Gamari Date: Wed, 22 Apr 2020 19:19:53 -0400 Subject: [PATCH 4/4] Add test for nonmoving gc heap census events --- ghc-events.cabal | 2 + test/Utils.hs | 1 + test/nonmoving-gc-census.eventlog | Bin 0 -> 8099 bytes test/nonmoving-gc-census.eventlog.reference | 340 ++++++++++++++++++++ 4 files changed, 343 insertions(+) create mode 100644 test/nonmoving-gc-census.eventlog create mode 100644 test/nonmoving-gc-census.eventlog.reference diff --git a/ghc-events.cabal b/ghc-events.cabal index ae1d275..8cbd2f4 100644 --- a/ghc-events.cabal +++ b/ghc-events.cabal @@ -38,6 +38,8 @@ extra-source-files: include/EventLogFormat.h test/mandelbrot-mmc-2011-06-14.eventlog.reference test/nonmoving-gc.eventlog test/nonmoving-gc.eventlog.reference + test/nonmoving-gc-census.eventlog + test/nonmoving-gc-census.eventlog.reference test/parallelTest.eventlog test/parallelTest.eventlog.reference test/pre77stop.eventlog diff --git a/test/Utils.hs b/test/Utils.hs index de5a0cd..ec7774e 100644 --- a/test/Utils.hs +++ b/test/Utils.hs @@ -6,6 +6,7 @@ files = map ("test/"++) , "queens-ghc-7.0.2.eventlog" , "mandelbrot-mmc-2011-06-14.eventlog" , "nonmoving-gc.eventlog" + , "nonmoving-gc-census.eventlog" , "parallelTest.eventlog" , "pre77stop.eventlog", "782stop.eventlog", "783stop.eventlog" , "sleep.h.eventlog" diff --git a/test/nonmoving-gc-census.eventlog b/test/nonmoving-gc-census.eventlog new file mode 100644 index 0000000000000000000000000000000000000000..eceee6b19cd6a682b9168e32e76a80c9ce367421 GIT binary patch literal 8099 zcmb7{4|Ej89mgk^4ZCjkh$JK?7Y`NzF+d=RVlEh3B_N1KE#Xh>vzpD_COLDrd+cra zCo1?Xtp=-A+hB|q6#<{3Re`70Kd)7gpa`$}z*4QYPgD#E38L0&OMf%7bGf~YddW+2 zv)}ptemgt!ncwWSgsjFE-EM?m1U~}&d21|Pvvt*OfzJ?Dbz6r&Fk}#eys*vS^?HyD z=IlD#jPbfNNpQ|0l2*0a3`1*-=&t+%8UfcMYs1af_l!Uy4)0Q}Rd3_o=WrsmAkr}3z+Fq_q=9*=9y?rF(IBcWTF9WjHgY7}zl7QTJrq4G$$ zvN*0=-1yPhjl_91YB-cK$2NG}cynTC5zMPwoJohJ)wF|9Ei z3EQh+&TLl>ADM#uIeG-rsy|>XCK=UBLZM`rZ6;r(CO@0ROkAi(&E>A-O_mw`p+G;G zve63{)v1OS)m6<1smpaM9ySfv=*JM>sH-g#kc_ID)!Y^ZBH}L7SYq-slWr^zTc&}1 z>T=BrW6a$FDv}_93;{t{ZuPP`u5{x_@2IOa3ulP&P3NEh1dXgCNCnL{!-mnj(u~Jf zNO2rwPrLdjkp44hf2hs9(YRi;aGgza$8BAUxVq0H zvChz%!mC%OP+3CyB^sWxgQuV~p*LqK>^C(?c7z>{y4jpc_k&YuB3h&FzI`bf-KZh# zy2dz-nuc)eGEFC@+&SSmUgRX;T&^;jYAz{w-)AaExTg3QnKo3L7F~5^bx5@~%z(xqib#R)oQoBVjg)$QvQg$m*E(ByR z(&DXZa44w(@(>E?j?%LM-yl(@s>p_+;UQ9IT-`GX4%xIk4y~RSVKXY48;wErg87C$ z*JN61V_UO2zN)P3d{?ebBv(E;UR1M*E);Chrf>?v4-;cSjS0s{5OTsYhV&*lcI?y= z^9ULJ+1!+BT#Lq1GCxW(k0lG`+*u96ZA$TNESTz{A)85v&lM84Eqp$5+>em~`Q}1N zOnE|{dkfi*Q~1L_uQ7}ZXRIY0)FLIk@U3KMV-~?4#-$F=qx)%WE!gT>f^B4YXC-c^ zski{JV3&0#NuEbmzALw>z5uTqP zH}504#}CPkcTZw}z-~)9citpn<5KSNBSCMGpn@Uyim%Z18175#nEk{#Iwk#3-`k{e z`4`8aTN+KEv8l-|gS9 zw%oa9HES!yx6fs5uMyh>ZRfs)a1@Px9IoNMUu^?irr+$KeTG&A4Gf;UsngZ`EsC1=)N+YEj zoVxflL}>Co*=QWu5_r;$#PkC(F-ymVoFL|yKRX|dsRg*P*Mj@SNyST!VrhGShbARn zmhpc0@sPgxXj~#BIj3tRbk3%{+mE`*15`Y5Et~)|5Zx~oeYLE0LP69Um@(jZ155r6 zUsZCMzO;quOP_*V8BDL2m|kB?bh@bmJNl5*+PMkQJrme-IihcevOkkF z*gr@9*G_>c@OdF~AIr%~lGif1=MMapX7I;J(pxVMYS41zzH23(e4?FxtzmtRyMHI7 z*KqLjli>$L@Vv_8J?oS4o5JKbKIGsh_`0h&_zAv!4<_T6 z#ge>voP(d>+rNN=pWu6YJqJI*cc7hvpE#klE^Yk82`l%eho3lM%@@POPn>Ymj)jvY$qE!?fsn@)Z>2?*YoKyXz-sAUC{G{IAV~)3P!)C|Z_XfN+3q?%d`!v(L z8z6^s_)2~I#xi~1Ux-espVar+uPJ^~-?5JV5ousS4+lSKVBNb6 zKLE-*lDXeqkEq#|Lo!5C$}H}N80$w?O#8Z9)5EBxAzPaKe_$8+O+YL z?`--LMM2)E!lG60qUgvQC;x=$r7f^N4u0~+*@)r?EvNd)oj3J3-p=Rh0l%3}j?SIW zGJO}GcLzVYbJxuYeK*kwesbsG{S-gB^Sv1qKe_Y7M2er>wPXxkM!BmYz`;-MTG@~B zgQviM+4nN{bI)V^oa%ShHBA2VVul~MJzp~UHJgK<-1Yh^9Q@?2-TOKC$z6N4aqyG7 z_RinG`>z_@i!$pW?49p@=B{i+6MIQ~bdNN!3rW znfo^)!wOztY?;HUVzKH=b}_#f;^#?Sd$qxc{CfPoq!dGQHzlf*HZjYi#@l z(>Fdch@aOSeURekHS;?teqM9Z4vL?5*^}Lr1@E$#4GwjLCCFh9C5JqD-E@I2pfbOulS42S2ZM`FIX~Uh9e%lkt;SlG+^{{JhrH)g1i1 SR^59X{Jd6ui3`8er~ePHH|n$i literal 0 HcmV?d00001 diff --git a/test/nonmoving-gc-census.eventlog.reference b/test/nonmoving-gc-census.eventlog.reference new file mode 100644 index 0000000..ab99800 --- /dev/null +++ b/test/nonmoving-gc-census.eventlog.reference @@ -0,0 +1,340 @@ +Event Types: +0: Create thread (size 4) +1: Run thread (size 4) +2: Stop thread (size 10) +3: Thread runnable (size 4) +4: Migrate thread (size 6) +8: Wakeup thread (size 6) +9: Starting GC (size 0) +10: Finished GC (size 0) +11: Request sequential GC (size 0) +12: Request parallel GC (size 0) +15: Create spark thread (size 4) +16: Log message (size variable) +18: Block marker (size 14) +19: User message (size variable) +20: GC idle (size 0) +21: GC working (size 0) +22: GC done (size 0) +25: Create capability set (size 6) +26: Delete capability set (size 4) +27: Add capability to capability set (size 6) +28: Remove capability from capability set (size 6) +29: RTS name and version (size variable) +30: Program arguments (size variable) +31: Program environment variables (size variable) +32: Process ID (size 8) +33: Parent process ID (size 8) +34: Spark counters (size 56) +35: Spark create (size 0) +36: Spark dud (size 0) +37: Spark overflow (size 0) +38: Spark run (size 0) +39: Spark steal (size 2) +40: Spark fizzle (size 0) +41: Spark GC (size 0) +43: Wall clock time (size 16) +44: Thread label (size variable) +45: Create capability (size 2) +46: Delete capability (size 2) +47: Disable capability (size 2) +48: Enable capability (size 2) +49: Total heap mem ever allocated (size 12) +50: Current heap size (size 12) +51: Current heap live data (size 12) +52: Heap static parameters (size 38) +53: GC statistics (size 58) +54: Synchronise stop-the-world GC (size 0) +55: Task create (size 18) +56: Task migrate (size 12) +57: Task delete (size 8) +58: User marker (size variable) +59: Empty event for bug #9003 (size 0) +160: Start of heap profile (size variable) +161: Cost center definition (size variable) +162: Start of heap profile sample (size 8) +163: Heap profile cost-centre sample (size variable) +164: Heap profile string sample (size variable) +165: End of heap profile sample (size 8) +166: Start of heap profile (biographical) sample (size 16) +167: Time profile cost-centre stack (size variable) +168: Start of a time profile (size 8) +181: User binary message (size variable) +200: Begin concurrent mark phase (size 0) +201: End concurrent mark phase (size 4) +202: Begin concurrent GC synchronisation (size 0) +203: End concurrent GC synchronisation (size 0) +204: Begin concurrent sweep (size 0) +205: End concurrent sweep (size 0) +206: Update remembered set flushed (size 2) +207: Nonmoving heap census (size 13) + +Events: +227855: capset 1: wall clock time 1587597517s 544758000ns (unix epoch) +229418: capset 0: pid 1158 +231368: capset 0: parent pid 25700 +233264: capset 0: RTS version "GHC-8.11.0.20200422 rts_thr_l" +233773: capset 0: args: ["nofib/shootout/binary-trees/Main","15","11","+RTS","-xn","-l-an"] +2789899: Starting nonmoving GC preparation +2811955: Marking roots for nonmoving GC +2813333: Finished marking roots for nonmoving GC +2813512: Finished nonmoving GC preparation +2872560: concurrent mark began +3320668: concurrent mark ended: marked 2869 objects +3337805: post-mark synchronization began +3337996: post-mark synchronization began +3682910: cap 0: update remembered set flushed by 0 +3683825: concurrent mark began +3692251: concurrent mark ended: marked 1042 objects +3692392: concurrent mark began +3692462: concurrent mark ended: marked 1 objects +3692552: concurrent mark began +3692621: concurrent mark ended: marked 1 objects +3716334: post-mark synchronization ended +3716512: post-mark synchronization ended +3720779: concurrent sweep began +3721599: concurrent sweep ended +3726029: nonmoving heap census 8: 0 active segments, 0 filled segments, 0 live blocks +3728053: nonmoving heap census 16: 0 active segments, 0 filled segments, 54 live blocks +3729679: nonmoving heap census 32: 0 active segments, 0 filled segments, 128 live blocks +3730314: nonmoving heap census 64: 0 active segments, 0 filled segments, 0 live blocks +3730776: nonmoving heap census 128: 0 active segments, 0 filled segments, 0 live blocks +3731036: nonmoving heap census 256: 0 active segments, 0 filled segments, 0 live blocks +3731339: nonmoving heap census 512: 0 active segments, 0 filled segments, 0 live blocks +3731574: nonmoving heap census 1024: 0 active segments, 0 filled segments, 0 live blocks +3731786: nonmoving heap census 2048: 0 active segments, 0 filled segments, 0 live blocks +3731990: nonmoving heap census 4096: 0 active segments, 0 filled segments, 0 live blocks +3732268: nonmoving heap census 8192: 0 active segments, 0 filled segments, 0 live blocks +3732469: nonmoving heap census 16384: 0 active segments, 0 filled segments, 0 live blocks +32362284: Starting nonmoving GC preparation +32371855: Marking roots for nonmoving GC +32373519: Finished marking roots for nonmoving GC +32373686: Finished nonmoving GC preparation +32557821: concurrent mark began +33910745: concurrent mark ended: marked 16928 objects +33914172: concurrent mark began +33916300: concurrent mark ended: marked 13 objects +33924796: post-mark synchronization began +33925033: post-mark synchronization began +34219802: cap 0: update remembered set flushed by 0 +34221200: concurrent mark began +34240845: concurrent mark ended: marked 1084 objects +34241350: concurrent mark began +34241419: concurrent mark ended: marked 1 objects +34241632: concurrent mark began +34241702: concurrent mark ended: marked 1 objects +34271446: post-mark synchronization ended +34271858: post-mark synchronization ended +34283960: concurrent sweep began +34559614: concurrent sweep ended +34563964: nonmoving heap census 8: 0 active segments, 0 filled segments, 0 live blocks +34576318: nonmoving heap census 16: 3 active segments, 0 filled segments, 1259 live blocks +34591543: nonmoving heap census 32: 6 active segments, 4 filled segments, 6385 live blocks +34596442: nonmoving heap census 64: 4 active segments, 1 filled segments, 1031 live blocks +34597260: nonmoving heap census 128: 0 active segments, 0 filled segments, 42 live blocks +34597718: nonmoving heap census 256: 0 active segments, 0 filled segments, 1 live blocks +34598055: nonmoving heap census 512: 0 active segments, 0 filled segments, 1 live blocks +34598375: nonmoving heap census 1024: 0 active segments, 0 filled segments, 4 live blocks +34598666: nonmoving heap census 2048: 0 active segments, 0 filled segments, 0 live blocks +34598997: nonmoving heap census 4096: 0 active segments, 0 filled segments, 0 live blocks +34599265: nonmoving heap census 8192: 0 active segments, 0 filled segments, 0 live blocks +34599501: nonmoving heap census 16384: 0 active segments, 0 filled segments, 0 live blocks +67279769: Starting nonmoving GC preparation +67281581: Marking roots for nonmoving GC +67282874: Finished marking roots for nonmoving GC +67283133: Finished nonmoving GC preparation +67370910: concurrent mark began +68397276: concurrent mark ended: marked 16875 objects +68398499: concurrent mark began +68399339: concurrent mark ended: marked 13 objects +68402178: post-mark synchronization began +68402344: post-mark synchronization began +68682534: cap 0: update remembered set flushed by 0 +68683459: concurrent mark began +68688876: concurrent mark ended: marked 352 objects +68689271: concurrent mark began +68689388: concurrent mark ended: marked 1 objects +68689515: concurrent mark began +68689626: concurrent mark ended: marked 1 objects +68704339: post-mark synchronization ended +68704591: post-mark synchronization ended +68710131: concurrent sweep began +68830040: concurrent sweep ended +68834054: nonmoving heap census 8: 0 active segments, 0 filled segments, 0 live blocks +68843935: nonmoving heap census 16: 3 active segments, 1 filled segments, 2855 live blocks +68858424: nonmoving heap census 32: 6 active segments, 3 filled segments, 5846 live blocks +68862979: nonmoving heap census 64: 4 active segments, 0 filled segments, 703 live blocks +68863622: nonmoving heap census 128: 0 active segments, 0 filled segments, 43 live blocks +68863967: nonmoving heap census 256: 0 active segments, 0 filled segments, 1 live blocks +68864313: nonmoving heap census 512: 0 active segments, 0 filled segments, 1 live blocks +68864669: nonmoving heap census 1024: 0 active segments, 0 filled segments, 5 live blocks +68865004: nonmoving heap census 2048: 0 active segments, 0 filled segments, 0 live blocks +68865354: nonmoving heap census 4096: 0 active segments, 0 filled segments, 0 live blocks +68865670: nonmoving heap census 8192: 0 active segments, 0 filled segments, 0 live blocks +68865931: nonmoving heap census 16384: 0 active segments, 0 filled segments, 0 live blocks +119827283: Starting nonmoving GC preparation +119830728: Marking roots for nonmoving GC +119831795: Finished marking roots for nonmoving GC +119831988: Finished nonmoving GC preparation +119938842: concurrent mark began +121053293: concurrent mark ended: marked 16438 objects +121056540: concurrent mark began +121057919: concurrent mark ended: marked 13 objects +121066516: post-mark synchronization began +121066859: post-mark synchronization began +121154737: cap 0: update remembered set flushed by 0 +121161224: concurrent mark began +121186040: concurrent mark ended: marked 1079 objects +121186533: concurrent mark began +121186646: concurrent mark ended: marked 1 objects +121186774: concurrent mark began +121186841: concurrent mark ended: marked 1 objects +121231348: post-mark synchronization ended +121231969: post-mark synchronization ended +121242597: concurrent sweep began +121385240: concurrent sweep ended +121390264: nonmoving heap census 8: 0 active segments, 0 filled segments, 0 live blocks +121405730: nonmoving heap census 16: 3 active segments, 0 filled segments, 1568 live blocks +121430287: nonmoving heap census 32: 7 active segments, 3 filled segments, 6270 live blocks +121436146: nonmoving heap census 64: 4 active segments, 1 filled segments, 897 live blocks +121437265: nonmoving heap census 128: 0 active segments, 0 filled segments, 43 live blocks +121437840: nonmoving heap census 256: 0 active segments, 0 filled segments, 1 live blocks +121438948: nonmoving heap census 512: 0 active segments, 0 filled segments, 1 live blocks +121439371: nonmoving heap census 1024: 0 active segments, 0 filled segments, 5 live blocks +121439723: nonmoving heap census 2048: 0 active segments, 0 filled segments, 0 live blocks +121440083: nonmoving heap census 4096: 0 active segments, 0 filled segments, 0 live blocks +121440368: nonmoving heap census 8192: 0 active segments, 0 filled segments, 0 live blocks +121441292: nonmoving heap census 16384: 0 active segments, 0 filled segments, 0 live blocks +148361407: Starting nonmoving GC preparation +148365127: Marking roots for nonmoving GC +148366468: Finished marking roots for nonmoving GC +148366670: Finished nonmoving GC preparation +148527085: concurrent mark began +149775840: concurrent mark ended: marked 15225 objects +149778324: concurrent mark began +149779513: concurrent mark ended: marked 13 objects +149810324: post-mark synchronization began +149810665: post-mark synchronization began +149850617: cap 0: update remembered set flushed by 0 +149851300: concurrent mark began +149866270: concurrent mark ended: marked 1049 objects +149866671: concurrent mark began +149866848: concurrent mark ended: marked 1 objects +149867039: concurrent mark began +149867202: concurrent mark ended: marked 1 objects +149874824: post-mark synchronization ended +149875168: post-mark synchronization ended +149901246: concurrent sweep began +150026135: concurrent sweep ended +150031083: nonmoving heap census 8: 0 active segments, 0 filled segments, 0 live blocks +150045140: nonmoving heap census 16: 3 active segments, 1 filled segments, 3342 live blocks +150066310: nonmoving heap census 32: 8 active segments, 3 filled segments, 5613 live blocks +150071204: nonmoving heap census 64: 4 active segments, 0 filled segments, 567 live blocks +150071885: nonmoving heap census 128: 0 active segments, 0 filled segments, 44 live blocks +150073125: nonmoving heap census 256: 0 active segments, 0 filled segments, 1 live blocks +150073558: nonmoving heap census 512: 0 active segments, 0 filled segments, 1 live blocks +150074077: nonmoving heap census 1024: 0 active segments, 0 filled segments, 6 live blocks +150074414: nonmoving heap census 2048: 0 active segments, 0 filled segments, 0 live blocks +150074832: nonmoving heap census 4096: 0 active segments, 0 filled segments, 0 live blocks +150075820: nonmoving heap census 8192: 0 active segments, 0 filled segments, 0 live blocks +150076102: nonmoving heap census 16384: 0 active segments, 0 filled segments, 0 live blocks +176942302: Starting nonmoving GC preparation +176945061: Marking roots for nonmoving GC +176946066: Finished marking roots for nonmoving GC +176946253: Finished nonmoving GC preparation +177039035: concurrent mark began +177741825: concurrent mark ended: marked 15542 objects +177744446: concurrent mark began +177745256: concurrent mark ended: marked 13 objects +177750528: post-mark synchronization began +177750635: post-mark synchronization began +177896570: cap 0: update remembered set flushed by 0 +177896939: concurrent mark began +177910616: concurrent mark ended: marked 1082 objects +177911218: concurrent mark began +177911307: concurrent mark ended: marked 1 objects +177911422: concurrent mark began +177911493: concurrent mark ended: marked 1 objects +177919949: post-mark synchronization ended +177920053: post-mark synchronization ended +177925925: concurrent sweep began +178017822: concurrent sweep ended +178020408: nonmoving heap census 8: 0 active segments, 0 filled segments, 0 live blocks +178026736: nonmoving heap census 16: 1 active segments, 1 filled segments, 2963 live blocks +178041784: nonmoving heap census 32: 7 active segments, 3 filled segments, 5977 live blocks +178045269: nonmoving heap census 64: 4 active segments, 1 filled segments, 757 live blocks +178045812: nonmoving heap census 128: 0 active segments, 0 filled segments, 44 live blocks +178046142: nonmoving heap census 256: 0 active segments, 0 filled segments, 1 live blocks +178046413: nonmoving heap census 512: 0 active segments, 0 filled segments, 1 live blocks +178046632: nonmoving heap census 1024: 0 active segments, 0 filled segments, 6 live blocks +178047048: nonmoving heap census 2048: 0 active segments, 0 filled segments, 0 live blocks +178047379: nonmoving heap census 4096: 0 active segments, 0 filled segments, 0 live blocks +178047876: nonmoving heap census 8192: 0 active segments, 0 filled segments, 0 live blocks +178048246: nonmoving heap census 16384: 0 active segments, 0 filled segments, 0 live blocks +202506857: Starting nonmoving GC preparation +202508058: Marking roots for nonmoving GC +202517509: Finished marking roots for nonmoving GC +202517677: Finished nonmoving GC preparation +202566458: concurrent mark began +203074473: concurrent mark ended: marked 16604 objects +203074950: concurrent mark began +203075547: concurrent mark ended: marked 13 objects +203078118: post-mark synchronization began +203078232: post-mark synchronization began +203131205: cap 0: update remembered set flushed by 0 +203131506: concurrent mark began +203140444: concurrent mark ended: marked 1083 objects +203140572: concurrent mark began +203140635: concurrent mark ended: marked 1 objects +203140714: concurrent mark began +203140783: concurrent mark ended: marked 1 objects +203149980: post-mark synchronization ended +203150083: post-mark synchronization ended +203153609: concurrent sweep began +203241257: concurrent sweep ended +203243717: nonmoving heap census 8: 0 active segments, 0 filled segments, 0 live blocks +203252554: nonmoving heap census 16: 3 active segments, 1 filled segments, 3188 live blocks +203263495: nonmoving heap census 32: 7 active segments, 4 filled segments, 6373 live blocks +203266345: nonmoving heap census 64: 4 active segments, 1 filled segments, 947 live blocks +203266828: nonmoving heap census 128: 0 active segments, 0 filled segments, 45 live blocks +203267099: nonmoving heap census 256: 0 active segments, 0 filled segments, 1 live blocks +203267302: nonmoving heap census 512: 0 active segments, 0 filled segments, 1 live blocks +203267563: nonmoving heap census 1024: 0 active segments, 0 filled segments, 7 live blocks +203267805: nonmoving heap census 2048: 0 active segments, 0 filled segments, 0 live blocks +203268121: nonmoving heap census 4096: 0 active segments, 0 filled segments, 0 live blocks +203268260: nonmoving heap census 8192: 0 active segments, 0 filled segments, 0 live blocks +203268439: nonmoving heap census 16384: 0 active segments, 0 filled segments, 0 live blocks +224422635: Starting nonmoving GC preparation +224424065: Marking roots for nonmoving GC +224424970: Finished marking roots for nonmoving GC +224425126: Finished nonmoving GC preparation +224506119: concurrent mark began +225279214: concurrent mark ended: marked 15033 objects +225280063: concurrent mark began +225280703: concurrent mark ended: marked 13 objects +225283313: post-mark synchronization began +225283479: post-mark synchronization began +225341600: cap 0: update remembered set flushed by 0 +225342335: concurrent mark began +225351353: concurrent mark ended: marked 1049 objects +225351605: concurrent mark began +225351675: concurrent mark ended: marked 1 objects +225351773: concurrent mark began +225351842: concurrent mark ended: marked 1 objects +225383632: post-mark synchronization ended +225383831: post-mark synchronization ended +225388468: concurrent sweep began +225553609: concurrent sweep ended +225557870: nonmoving heap census 8: 0 active segments, 0 filled segments, 0 live blocks +225572051: nonmoving heap census 16: 3 active segments, 0 filled segments, 1860 live blocks +225587504: nonmoving heap census 32: 6 active segments, 3 filled segments, 5705 live blocks +225592583: nonmoving heap census 64: 4 active segments, 0 filled segments, 621 live blocks +225593429: nonmoving heap census 128: 0 active segments, 0 filled segments, 46 live blocks +225593797: nonmoving heap census 256: 0 active segments, 0 filled segments, 1 live blocks +225594147: nonmoving heap census 512: 0 active segments, 0 filled segments, 1 live blocks +225594554: nonmoving heap census 1024: 0 active segments, 0 filled segments, 8 live blocks +225594804: nonmoving heap census 2048: 0 active segments, 0 filled segments, 0 live blocks +225595452: nonmoving heap census 4096: 0 active segments, 0 filled segments, 0 live blocks +225596376: nonmoving heap census 8192: 0 active segments, 0 filled segments, 0 live blocks +225597481: nonmoving heap census 16384: 0 active segments, 0 filled segments, 0 live blocks +