Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Bump the revision of mmtk-core and ruby repos #109

Merged
merged 2 commits into from
Oct 11, 2024

Conversation

wks
Copy link
Collaborator

@wks wks commented Oct 11, 2024

Updated mmtk-core to fix a race that caused GC workers to sometimes observe copied objects not having VO bits. See:
mmtk/mmtk-core#1214

The ruby repo is merged with the official master branch.

Fixes: #106

Updated mmtk-core to fix a race that caused GC workers to sometimes
observe copied objects not having VO bits.  See:
mmtk/mmtk-core#1214

The ruby repo is merged with the official master branch.

Fixes: mmtk#106
@wks
Copy link
Collaborator Author

wks commented Oct 11, 2024

#169 test_eval.rb:348: failed once due to timeout. It famously constructs a very large source code snippet and evaluate it, and is likely to take a very long time to finish. I think the CI is simply under a slightly heavier load so that the test case didn't finish in 3 minutes. The log https://github.com/mmtk/mmtk-ruby/actions/runs/11289796995/job/31400358051?pr=109 shows that it is doing lots of GC, each of which took up to 2 seconds. (correction: The log shows long GC times, but those are from test_fiber.rb where it tries to determine the maximum number of fibers) Maybe the heuristics of the MemBalancer is not good enough for this extreme use case. I'll rerun the tests.

@wks
Copy link
Collaborator Author

wks commented Oct 11, 2024

When running locally, I observed that the heap size grew too slowly when using MemBalancer for the following test case:

puts "Creating the hash..."

hash = {}

puts "Preparing the hash..."

("aaaa".."matz").each_with_index do |s, i|
  hash[s] = i
end

puts "Doing the eval..."

begin
  eval "class C; @@h = #{hash.inspect}; end"
end

puts "Done. Goodbye!"

Here is a log when using MarkSweep, using the default dynamic heap size setting that ranges from 2M to 80% total physical memory (which is hardly reachable).

$ /home/wks/projects/mmtk-github/ruby/build-release/miniruby -I/home/wks/projects/mmtk-github/ruby/lib -I/home/wks/projects/mmtk-github/ruby/build-release -I/home/wks/projects/mmtk-github/ruby/build-release/.ext/common  -r/home/wks/projects/mmtk-github/ruby/build-release/x86_64-linux-fake --mmtk --mmtk-plan=MarkSweep -W0 ~/code/ruby/gctest/eval039.rb
[2024-10-11T13:22:05Z INFO  mmtk::memory_manager] Initialized MMTk with MarkSweep (DynamicHeapSize(1048576, 26656869520))
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (674/256 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (658/701 pages, took 1 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (714/701 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (698/742 pages, took 1 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (758/742 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (726/768 pages, took 1 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (800/768 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (784/819 pages, took 1 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (858/819 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (842/878 pages, took 1 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (882/878 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (864/895 pages, took 1 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (905/895 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (889/929 pages, took 1 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (934/929 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (902/945 pages, took 1 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (961/945 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (894/929 pages, took 1 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (932/929 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (898/933 pages, took 1 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (934/933 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (900/938 pages, took 1 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (950/938 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (900/944 pages, took 1 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (951/944 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (901/959 pages, took 1 ms)
Creating the hash...
Preparing the hash...
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (975/959 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (927/985 pages, took 2 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (1005/985 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (987/1042 pages, took 1 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (1051/1042 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (1035/1085 pages, took 1 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (1130/1085 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (1114/1162 pages, took 2 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (1180/1162 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (1162/1214 pages, took 1 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (1228/1214 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (1212/1254 pages, took 1 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (1284/1254 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (1268/1311 pages, took 2 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (1318/1311 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (1302/1353 pages, took 1 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (1368/1353 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (1350/1394 pages, took 1 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (1496/1394 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (1480/1526 pages, took 1 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (1528/1526 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (1512/1570 pages, took 1 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (1578/1570 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (1562/1603 pages, took 1 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (1690/1603 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (1674/1720 pages, took 1 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (1724/1720 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (1706/1770 pages, took 2 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (1772/1770 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (1756/1803 pages, took 2 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (1806/1803 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (1790/1840 pages, took 2 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (1856/1840 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (1838/1883 pages, took 2 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (1888/1883 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (1872/1919 pages, took 2 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (1922/1919 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (1904/1948 pages, took 2 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (1954/1948 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (1938/1980 pages, took 2 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (1988/1980 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (1970/2014 pages, took 2 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (2277/2014 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (2259/2310 pages, took 2 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (2325/2310 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (2309/2402 pages, took 3 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (2409/2402 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (2391/2447 pages, took 2 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (2697/2447 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (2679/2735 pages, took 3 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (2745/2735 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (2729/2817 pages, took 3 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (2829/2817 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (2811/2866 pages, took 4 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (2877/2866 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (2861/2914 pages, took 2 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (2927/2914 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (2911/2954 pages, took 2 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (2961/2954 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (2943/2988 pages, took 2 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (2993/2988 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (2977/3022 pages, took 3 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (3027/3022 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (3009/3056 pages, took 2 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (3059/3056 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (3043/3088 pages, took 3 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (3093/3088 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (3075/3124 pages, took 3 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (3125/3124 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (3109/3158 pages, took 4 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (3159/3158 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (3141/3195 pages, took 4 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (3207/3195 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (3191/3241 pages, took 3 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (3257/3241 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (3241/3295 pages, took 4 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (3307/3295 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (3291/3344 pages, took 3 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (3357/3344 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (3339/3390 pages, took 4 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (3885/3390 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (3869/3930 pages, took 3 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (3935/3930 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (3917/4014 pages, took 4 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (4513/4014 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (4495/4562 pages, took 4 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (4579/4562 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (4561/4669 pages, took 5 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (4677/4669 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (4661/4720 pages, took 4 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (4727/4720 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (4711/4759 pages, took 4 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (4777/4759 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (4759/4807 pages, took 4 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (4809/4807 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (4793/4842 pages, took 4 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (4843/4842 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (4825/4873 pages, took 5 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (4875/4873 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (4859/4909 pages, took 4 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (4925/4909 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (4909/4961 pages, took 4 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (4975/4961 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (4957/5015 pages, took 6 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (5023/5015 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (5007/5065 pages, took 4 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (5073/5065 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (5057/5111 pages, took 5 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (5123/5111 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (5107/5163 pages, took 4 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (5173/5163 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (5155/5211 pages, took 6 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (5221/5211 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (5205/5261 pages, took 5 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (5271/5261 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (5255/5311 pages, took 5 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (5321/5311 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (5305/5365 pages, took 7 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (5371/5365 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (5353/5415 pages, took 6 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (5419/5415 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (5403/5459 pages, took 6 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (5469/5459 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (5453/5511 pages, took 5 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (5519/5511 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (5503/5559 pages, took 5 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (5569/5559 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (5551/5605 pages, took 6 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (5617/5605 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (5601/5657 pages, took 5 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (5667/5657 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (5651/5708 pages, took 6 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (5717/5708 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (5701/5758 pages, took 5 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (5767/5758 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (5749/5808 pages, took 6 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (5815/5808 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (5799/5855 pages, took 6 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (5865/5855 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (5849/5906 pages, took 5 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (5915/5906 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (5899/5956 pages, took 7 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (5965/5956 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (5947/6010 pages, took 7 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (7021/6010 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (7005/7086 pages, took 7 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (7087/7086 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (7071/7205 pages, took 7 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (8127/7205 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (8111/8192 pages, took 7 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (8193/8192 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (8177/8304 pages, took 6 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (8309/8304 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (8293/8359 pages, took 7 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (8375/8359 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (8359/8433 pages, took 9 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (8441/8433 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (8425/8486 pages, took 7 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (8491/8486 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (8475/8535 pages, took 7 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (8541/8535 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (8523/8581 pages, took 7 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (8589/8581 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (8573/8632 pages, took 7 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (8639/8632 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (8623/8687 pages, took 9 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (8689/8687 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (8673/8738 pages, took 7 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (8739/8738 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (8721/8781 pages, took 7 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (8787/8781 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (8771/8832 pages, took 10 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (8837/8832 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (8821/8890 pages, took 9 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (8903/8890 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (8887/8952 pages, took 11 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (8953/8952 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (8937/9010 pages, took 11 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (9019/9010 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (9003/9065 pages, took 8 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (9069/9065 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (9051/9113 pages, took 8 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (9117/9113 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (9101/9158 pages, took 8 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (9167/9158 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (9151/9211 pages, took 8 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (9217/9211 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (9201/9268 pages, took 12 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (9283/9268 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (9267/9332 pages, took 9 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (9333/9332 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (9315/9381 pages, took 9 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (9399/9381 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (9381/9440 pages, took 9 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (9447/9440 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (9431/9496 pages, took 9 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (9497/9496 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (9481/9543 pages, took 10 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (9547/9543 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (9531/9597 pages, took 11 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (9613/9597 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (9597/9665 pages, took 9 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (9679/9665 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (9663/9728 pages, took 9 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (9729/9728 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (9711/9775 pages, took 10 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (9777/9775 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (9761/9824 pages, took 12 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (9827/9824 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (9811/9879 pages, took 10 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (9893/9879 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (9877/9941 pages, took 10 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (9943/9941 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (9927/9994 pages, took 10 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10009/9994 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (9993/10058 pages, took 13 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10059/10058 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (10041/10114 pages, took 10 ms)
Doing the eval...
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10125/10114 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (10075/10141 pages, took 12 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10157/10141 pages)
[2024-10-11T13:22:05Z INFO  mmtk::scheduler::scheduler] End of GC (10075/10170 pages, took 12 ms)
[2024-10-11T13:22:05Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10182/10170 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10092/10195 pages, took 12 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10203/10195 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10106/10206 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] los: Triggering collection (10230/10206 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10106/10241 pages, took 9 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10246/10241 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10134/10221 pages, took 12 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10232/10221 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10134/10235 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] los: Triggering collection (10265/10235 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10134/10311 pages, took 11 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10315/10311 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10191/10256 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10257/10256 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10191/10305 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10307/10305 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10191/10272 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10273/10272 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10191/10280 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10289/10280 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10191/10273 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] los: Triggering collection (10420/10273 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10175/10470 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10486/10470 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10305/10373 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10387/10373 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10305/10446 pages, took 13 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10453/10446 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10305/10392 pages, took 11 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10403/10392 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10305/10403 pages, took 12 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10421/10403 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10305/10397 pages, took 11 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10403/10397 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10305/10393 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10403/10393 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10305/10390 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10403/10390 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10305/10397 pages, took 13 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10403/10397 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10305/10393 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] los: Triggering collection (10761/10393 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10289/10807 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10811/10807 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10533/10602 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10615/10602 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10533/10688 pages, took 9 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10697/10688 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10533/10621 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10631/10621 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10533/10641 pages, took 14 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10649/10641 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10533/10629 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10631/10629 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10533/10619 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10631/10619 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10533/10616 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10631/10616 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10533/10627 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10631/10627 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10533/10621 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10631/10621 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10533/10628 pages, took 13 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10631/10628 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10533/10629 pages, took 11 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10631/10629 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10533/10622 pages, took 11 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10631/10622 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10533/10621 pages, took 11 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10631/10621 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10533/10624 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10631/10624 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10533/10618 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10631/10618 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10533/10624 pages, took 14 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10631/10624 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10533/10622 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (10631/10622 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10533/10619 pages, took 12 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] los: Triggering collection (11444/10619 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10533/11510 pages, took 13 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11526/11510 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11085 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11086/11085 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11174 pages, took 13 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11186/11174 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11073 pages, took 13 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11086/11073 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11092 pages, took 11 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11104/11092 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11073 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11086/11073 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11082 pages, took 12 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11086/11082 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11084 pages, took 12 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11086/11084 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11083 pages, took 11 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11086/11083 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11077 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11086/11077 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11074 pages, took 13 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11086/11074 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11081 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11086/11081 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11080 pages, took 12 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11086/11080 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11075 pages, took 13 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11086/11075 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11062 pages, took 9 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11070/11062 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11075 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11086/11075 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11063 pages, took 13 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11070/11063 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11089 pages, took 11 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11104/11089 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11074 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11086/11074 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11082 pages, took 13 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11086/11082 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11084 pages, took 11 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11086/11084 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11075 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11086/11075 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11075 pages, took 12 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11086/11075 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11094 pages, took 13 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11104/11094 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11084 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11086/11084 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11075 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11086/11075 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11080 pages, took 14 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11086/11080 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11082 pages, took 12 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11086/11082 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11079 pages, took 13 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11086/11079 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11081 pages, took 13 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11086/11081 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11082 pages, took 14 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11086/11082 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11084 pages, took 13 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11086/11084 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11063 pages, took 10 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11070/11063 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11074 pages, took 9 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (11086/11074 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/11079 pages, took 11 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] los: Triggering collection (12841/11079 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (10988/12858 pages, took 12 ms)
[2024-10-11T13:22:06Z INFO  mmtk::util::heap::gc_trigger] [POLL] los: Triggering collection (13742/12858 pages)
[2024-10-11T13:22:06Z INFO  mmtk::scheduler::scheduler] End of GC (11898/12893 pages, took 10 ms)
[2024-10-11T13:22:07Z INFO  mmtk::util::heap::gc_trigger] [POLL] los: Triggering collection (13655/12893 pages)
[2024-10-11T13:22:07Z INFO  mmtk::scheduler::scheduler] End of GC (10995/11955 pages, took 12 ms)
Done. Goodbye!

The heap size increases slowly while preparing the hash, and stays almost the same while evaluating. The problems is, the heap size doesn't increase fast enough. After each GC, it only increases the heap size by a small amount, while the heap consists of mostly live objects. Therefore, the next GC will happen very soon. As a result, it triggers GC way too often, and each GC costs, especially for slow GC algorithms like MarkSweep. The command line arguments -I/path/to/ruby/lib -I/path/to/ruby/build-release -I/path/to/ruby/build-release/.ext/common -r/path/to/ruby/build-release/x86_64-linux-fake only make things worse because it preloads more code and increases the heap size.

If we change to a fixed heap size (such as 100M), that test case will finish very quickly. The following is what happens when using a fixed 80M heap size.

$ MMTK_GC_TRIGGER='FixedHeapSize:80m' /home/wks/projects/mmtk-github/ruby/build-debug/miniruby -I/home/wks/projects/mmtk-github/ruby/lib -I/home/wks/projects/mmtk-github/ruby/build-debug -I/home/wks/projects/mmtk-github/ruby/build-debug/.ext/common  -r/home/wks/projects/mmtk-github/ruby/build-debug/x86_64-linux-fake --mmtk --mmtk-plan=MarkSweep -W0 ~/code/ruby/gctest/eval039.rb
[2024-10-11T13:35:43Z INFO  mmtk::memory_manager] Initialized MMTk with MarkSweep (FixedHeapSize(83886080))
Creating the hash...
Preparing the hash...
Doing the eval...
[2024-10-11T13:35:44Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (20485/20480 pages)
[2024-10-11T13:35:44Z INFO  mmtk::scheduler::scheduler] End of GC (17235/20480 pages, took 253 ms)
[2024-10-11T13:35:45Z INFO  mmtk::util::heap::gc_trigger] [POLL] ms: Triggering collection (20481/20480 pages)
[2024-10-11T13:35:45Z INFO  mmtk::scheduler::scheduler] End of GC (18015/20480 pages, took 251 ms)
Done. Goodbye!

I chose to use dynamic heap size exactly because it triggers GC very often, which can be used to stress the GC. But for bootstraptest/test_eval.rb (more precisely, that particular test case), the GC time is simply unreasonable due to the not-so-smart MemBalancer algorithm. I'll just change the CI script to treat bootstraptest/test_eval.rb specially and test it with a fixed heap size.

Run bootstraptest/test_eval.rb with a fixed heap size.
@wks wks merged commit 08a7e8d into mmtk:master Oct 11, 2024
8 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Destination not object when scanning iseq
1 participant