LUMIERA.clone/doc/devel/dump/2023-12-09.Scheduler-Integration/Dump-02
Ichthyostega 7847e3156c Scheduler-test: investigate processing patterns
Some test-runs performed excitingly smooth,
but in one case the processing was was drastically delayed,
due to heavy contention. The relevance of this incident is not clear yet,
since this test run uses a rather atypical load with very short actual work jobs.

Anyway, the dump-logs are documented with this commit.
2023-12-09 04:30:35 +01:00

497 lines
15 KiB
Text

invokeTestCase: ++------------------- invoking TEST: vault::gear::test::TestChainLoad_test
#--◆--# offset() ? = 696
#--◆--# testLoad.getHash() ? = 5982496738762178821
#--◆--# offset() ? = 987
+++ 7D: seed(num:64)
ANCHOR=0 preRoll=200
‖▷▷▷‖ 7D: @ -69 EMPTY
‖IGN‖ wof:8
‖SCH‖ 7D: @1164 ○ start=-155 dead:100000
!◆!plan...to:63 |curr=0 (max:64)
|n.(0,lev:0)
... dispose(i=0,lev:0) -> @0
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @1345 ○ start=0 dead:10000
!◆! 7D: calc(i=0, lev:0)
|n.(1,lev:1)
... dispose(i=1,lev:1) -> @1000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @1457 ○ start=1000 dead:10000
!◆! 7D: calc(i=1, lev:1)
|n.(2,lev:2)
... dispose(i=2,lev:2) -> @2000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @1553 ○ start=2000 dead:10000
|n.(3,lev:2)
... dispose(i=3,lev:2) -> @2000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @1617 ○ start=2000 dead:10000
|n.(4,lev:3)
... dispose(i=4,lev:3) -> @3000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @1681 ○ start=3000 dead:10000
|n.(5,lev:3)
... dispose(i=5,lev:3) -> @3000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @1742 ○ start=3000 dead:10000
|n.(6,lev:3)
... dispose(i=6,lev:3) -> @3000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @1807 ○ start=3000 dead:10000
|n.(7,lev:4)
... dispose(i=7,lev:4) -> @4000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @1872 ○ start=4000 dead:10000
|n.(8,lev:4)
... dispose(i=8,lev:4) -> @4000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @1935 ○ start=4000 dead:10000
|n.(9,lev:4)
... dispose(i=9,lev:4) -> @4000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @2000 ○ start=4000 dead:10000
|n.(10,lev:4)
... dispose(i=10,lev:4) -> @4000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @2067 ○ start=4000 dead:10000
|n.(11,lev:5)
... dispose(i=11,lev:5) -> @5000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @2133 ○ start=5000 dead:10000
|n.(12,lev:5)
... dispose(i=12,lev:5) -> @5000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @2200 ○ start=5000 dead:10000
|n.(13,lev:5)
... dispose(i=13,lev:5) -> @5000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @2264 ○ start=5000 dead:10000
|n.(14,lev:5)
... dispose(i=14,lev:5) -> @5000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @2327 ○ start=5000 dead:10000
|n.(15,lev:6)
... dispose(i=15,lev:6) -> @6000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @2394 ○ start=6000 dead:10000
|n.(16,lev:6)
... dispose(i=16,lev:6) -> @6000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @2462 ○ start=6000 dead:10000
|n.(17,lev:6)
... dispose(i=17,lev:6) -> @6000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @2527 ○ start=6000 dead:10000
|n.(18,lev:6)
... dispose(i=18,lev:6) -> @6000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @2590 ○ start=6000 dead:10000
|n.(19,lev:6)
... dispose(i=19,lev:6) -> @6000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @2655 ○ start=6000 dead:10000
|n.(20,lev:7)
... dispose(i=20,lev:7) -> @7000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @2720 ○ start=7000 dead:10000
|n.(21,lev:7)
... dispose(i=21,lev:7) -> @7000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @2785 ○ start=7000 dead:10000
|n.(22,lev:7)
... dispose(i=22,lev:7) -> @7000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @2850 ○ start=7000 dead:10000
|n.(23,lev:7)
... dispose(i=23,lev:7) -> @7000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @2913 ○ start=7000 dead:10000
|n.(24,lev:7)
... dispose(i=24,lev:7) -> @7000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @2979 ○ start=7000 dead:10000
|n.(25,lev:8)
... dispose(i=25,lev:8) -> @8000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @3045 ○ start=8000 dead:10000
|n.(26,lev:8)
... dispose(i=26,lev:8) -> @8000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @3107 ○ start=8000 dead:10000
|n.(27,lev:8)
... dispose(i=27,lev:8) -> @8000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @3179 ○ start=8000 dead:10000
|n.(28,lev:8)
... dispose(i=28,lev:8) -> @8000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @3243 ○ start=8000 dead:10000
|n.(29,lev:8)
... dispose(i=29,lev:8) -> @8000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @3308 ○ start=8000 dead:10000
|n.(30,lev:9)
... dispose(i=30,lev:9) -> @9000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @3372 ○ start=9000 dead:10000
|n.(31,lev:9)
... dispose(i=31,lev:9) -> @9000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @3438 ○ start=9000 dead:10000
|n.(32,lev:9)
... dispose(i=32,lev:9) -> @9000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @3503 ○ start=9000 dead:10000
|n.(33,lev:9)
... dispose(i=33,lev:9) -> @9000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @3566 ○ start=9000 dead:10000
|n.(34,lev:9)
... dispose(i=34,lev:9) -> @9000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @3632 ○ start=9000 dead:10000
|n.(35,lev:10)
... dispose(i=35,lev:10) -> @10000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @3699 ○ start=10000 dead:10000
|n.(36,lev:10)
... dispose(i=36,lev:10) -> @10000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @3764 ○ start=10000 dead:10000
|n.(37,lev:10)
... dispose(i=37,lev:10) -> @10000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @3829 ○ start=10000 dead:10000
|n.(38,lev:10)
... dispose(i=38,lev:10) -> @10000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @3892 ○ start=10000 dead:10000
|n.(39,lev:10)
... dispose(i=39,lev:10) -> @10000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @3960 ○ start=10000 dead:10000
|n.(40,lev:11)
... dispose(i=40,lev:11) -> @11000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @4026 ○ start=11000 dead:10000
|n.(41,lev:11)
... dispose(i=41,lev:11) -> @11000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @4091 ○ start=11000 dead:10000
|n.(42,lev:11)
... dispose(i=42,lev:11) -> @11000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @4155 ○ start=11000 dead:10000
|n.(43,lev:11)
... dispose(i=43,lev:11) -> @11000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @4221 ○ start=11000 dead:10000
|n.(44,lev:11)
... dispose(i=44,lev:11) -> @11000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @4287 ○ start=11000 dead:10000
|n.(45,lev:12)
... dispose(i=45,lev:12) -> @12000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @4351 ○ start=12000 dead:10000
|n.(46,lev:12)
... dispose(i=46,lev:12) -> @12000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @4414 ○ start=12000 dead:10000
|n.(47,lev:12)
... dispose(i=47,lev:12) -> @12000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @4482 ○ start=12000 dead:10000
|n.(48,lev:12)
... dispose(i=48,lev:12) -> @12000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @4545 ○ start=12000 dead:10000
|n.(49,lev:12)
... dispose(i=49,lev:12) -> @12000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @4611 ○ start=12000 dead:10000
|n.(50,lev:13)
... dispose(i=50,lev:13) -> @13000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @4675 ○ start=13000 dead:10000
|n.(51,lev:13)
... dispose(i=51,lev:13) -> @13000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @4738 ○ start=13000 dead:10000
|n.(52,lev:13)
... dispose(i=52,lev:13) -> @13000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @4802 ○ start=13000 dead:10000
|n.(53,lev:13)
... dispose(i=53,lev:13) -> @13000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @4869 ○ start=13000 dead:10000
|n.(54,lev:13)
... dispose(i=54,lev:13) -> @13000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @4935 ○ start=13000 dead:10000
|n.(55,lev:14)
... dispose(i=55,lev:14) -> @14000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @5001 ○ start=14000 dead:10000
|n.(56,lev:14)
... dispose(i=56,lev:14) -> @14000
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @5068 ○ start=14000 dead:10000
|n.(57,lev:14)
... dispose(i=57,lev:14) -> @14000
‖•△•‖ wof:8 HT:2000
‖SCH‖ 7D: @5134 ○ start=14000 dead:10000
|n.(58,lev:14)
... dispose(i=58,lev:14) -> @14000
‖•△•‖ wof:8 HT:2000
‖SCH‖ 7D: @5196 ○ start=14000 dead:10000
|n.(59,lev:14)
... dispose(i=59,lev:14) -> @14000
‖•△•‖ wof:8 HT:2000
·‖ AF: @ 5179 HT:2000 -> ▶ 2000
‖SCH‖ 7D: @5263 ○ start=14000 dead:10000
|n.(60,lev:15)
... dispose(i=60,lev:15) -> @15000
‖•△•‖ wof:8 HT:2000
‖SCH‖ 7D: @5375 ○ start=15000 dead:10000
!◆! AF: calc(i=2, lev:2) |n.(61,lev:15)
... dispose(i=61,lev: ·‖ 30: @ 5445 HT:3000 -> ▶ 200015
) -> @15000
‖•△•‖ wof:8 HT:3000 ·‖ 30: @ 5475 HT:3000 -> ▶ 3000
‖SCH‖ 7D: @5499 ○ start=15000 dead:10000
·‖ AF: @ 5467 HT:3000 -> ∘
·‖ 30: @ 5532 HT:3000 -> ▶ 3000
|n.(62,lev:15) ·‖ 30: @ 5555 HT:4000 -> ▶ 3000
·‖ AF: @ 5569 HT:4000 -> ∘
... dispose(i=62,lev:15) -> @15000
!◆! 30: calc(i=5, lev:3)
‖•△•‖ wof:8 HT:4000 ·‖ AF: @ 5611 HT:4000 -> ▶ 4000
·‖ 30: @ 5640 HT:4000 -> ∘
‖SCH‖ 7D: @5651 ○ start=15000 dead:10000
·‖ 30: @ 5656 HT:4000 -> ∘
·‖ 30: @ 5692 HT:4000 -> ▶ 4000
|n.(63,lev:16)
·‖ 30: @ 5715 HT:4000 -> ▶ 4000
!◆! ·‖ 30: @ 5739 HT:4931 -> ▶ 4000
AF: calc(i=7, lev:4)
!◆! ... dispose(i=63,lev:16) -> @16000
30: calc(i=9, lev:4)
·‖ 30: @ 5806 HT:4931 -> ∘
‖•△•‖ wof:8 HT:4931
‖SCH‖ 7D: @5824 ○ start=16000 dead:10000
·‖ 30: @ 5824 HT:5000 -> ▶ 4931
‖▷▷▷‖ 30: @ 5843 HT:5000
!◆! AF: calc(i=11, lev:5)
+++ 7D: Continuation(lastNode=63, levelDone=16, work_left:false)
·‖ 30: @ 5887 HT:5000 -> ▶ 5000
·‖ 30: @ 5907 HT:5000 -> ▶ 5000
·‖ AF: @ 5908 HT:5000 -> ∘
‖•△•‖ wof:8 HT:5000
!◆! 30: calc(i=13, lev:5)
·‖ 30: @ 5969 HT:5000 -> ∘‖SCH‖ 7D: @5968 ○ start=17000 dead:100000 ·‖ AF: @ 5952 HT:5000 -> ▶ 5000
·‖ 30: @ 6018 HT:5000 -> ∘
·‖ 30: @ 6032 HT:5440 -> ∘
·‖ AF: @ 6023 HT:5440 -> ▶ 5000
·‖ 30: @ 6047 HT:5440 -> ∘
·‖ 30: @ 6073 HT:5440 -> ∘
·‖ 30: @ 6086 HT:5633 -> ∘
·‖ AF: @ 6073 HT:5633 -> ▶ 5440
·‖ 30: @ 6103 HT:5633 -> ∘
·‖ 30: @ 6132 HT:5800 -> ▶ 5633
·‖ 30: @ 6148 HT:5893 -> ▶ 5800
!◆! AF: calc(i=4, lev:3)
!◆! 30: calc(i=12, lev:5)
·‖ 30: @ 6218 HT:5962 -> ▶ 5893
!◆! 30: calc(i=16, lev:6)
!◆! AF: calc(i=8, lev:4)
·‖ 30: @ 6258 HT:6000 -> ▶ 5962
!◆! 30: calc(i=18, lev:6)
·‖ 30: @ 6336 HT:6000 -> ∘
·‖ AF: @ 6315 HT:6000 -> ▶ 6000
·‖ 30: @ 6353 HT:6000 -> ∘
·‖ 30: @ 6380 HT:6000 -> ▶ 6000
·‖ 30: @ 6398 HT:6000 -> ▶ 6000
·‖ 30: @ 6413 HT:6000 -> ▶ 6000
!◆! AF: calc(i=15, lev:6)
!◆! 30: calc(i=17, lev:6)
!◆! 30: calc(i=21, lev:7)
·‖ 30: @ 6482 HT:6331 -> ▶ 6000
·‖ 30: @ 6498 HT:7000 -> ▶ 6331
!◆! AF: calc(i=20, lev:7)
!◆! AF: calc(i=26, lev:8)
·‖ 30: @ 7069 HT:7000 -> ▶ 7000
!◆! 30: calc(i=24, lev:7)
!◆! 30: calc(i=29, lev:8)
·‖ 30: @ 7153 HT:7000 -> ▶ 7000
·‖ 30: @ 7168 HT:7000 -> ▶ 7000
!◆! 30: calc(i=22, lev:7)
!◆! 30: calc(i=28, lev:8)
!◆! 30: calc(i=33, lev:9)
·‖ 30: @ 7256 HT:7000 -> ▶ 7000
·‖ 30: @ 7272 HT:8000 -> ▶ 7000
·‖ 30: @ 8057 HT:8000 -> ▶ 8000
·‖ 30: @ 8084 HT:8000 -> ▶ 8000
!◆! 30: calc(i=27, lev:8)
!◆! 30: calc(i=31, lev:9)
·‖ 30: @ 8159 HT:8000 -> ▶ 8000
!◆! 30: calc(i=25, lev:8)
!◆! 30: calc(i=30, lev:9)
!◆! 30: calc(i=36, lev:10)
·‖ 30: @ 8246 HT:8000 -> ▶ 8000
·‖ D9: @ 8246 HT:8000 -> ∘
·‖ D9: @ 8268 HT:9000 -> ∘ ·‖ 30: @ 8267 HT:9000 -> ▶ 8000
·‖ 30: @ 9069 HT:9000 -> ▶ 9000
·‖ 30: @ 9099 HT:9000 -> ▶ 9000
·‖ 30: @ 9113 HT:9000 -> ▶ 9000
!◆! 30: calc(i=34, lev:9)
!◆! 30: calc(i=39, lev:10)
·‖ 30: @ 9187 HT:9000 -> ▶ 9000
·‖ 30: @ 9202 HT:10000 -> ▶ 9000
!◆! 30: calc(i=32, lev:9)
!◆! 30: calc(i=38, lev:10)
!◆! 30: calc(i=43, lev:11)
·‖ 30: @ 10069 HT:10000 -> ▶ 10000
·‖ 30: @ 10099 HT:10000 -> ▶ 10000
·‖ 30: @ 10121 HT:10000 -> ▶ 10000
·‖ 30: @ 10135 HT:10000 -> ▶ 10000
!◆! 30: calc(i=37, lev:10)
!◆! 30: calc(i=41, lev:11)
·‖ 30: @ 10206 HT:11000 -> ▶ 10000
!◆! 30: calc(i=35, lev:10)
!◆! 30: calc(i=40, lev:11)
!◆! 30: calc(i=46, lev:12)
·‖ F8: @ 11005 HT:11000 -> ▶ 11000
·‖ F8: @ 11090 HT:11000 -> ▶ 11000
!◆! F8: calc(i=44, lev:11)
·‖ 30: @ 11140 HT:11000 -> ▶ 11000
·‖ F8: @ 11259 HT:11000 -> ∘
·‖ 30: @ 11286 HT:11000 -> ▶ 11000
·‖ F8: @ 11300 HT:11000 -> ∘
·‖ F8: @ 11369 HT:11242 -> ▶ 11000
!◆! 30: calc(i=42, lev:11)
·‖ F8: @ 11415 HT:12000 -> ▶ 11242
!◆! F8: calc(i=49, lev:12)
·‖ F8: @ 11624 HT:12000 -> ▶ 11484
!◆! F8: calc(i=48, lev:12)
!◆! F8: calc(i=53, lev:13)
·‖ 30: @ 12071 HT:12000 -> ∘
·‖ B5: @ 12062 HT:12000 -> ▶ 12000
·‖ 30: @ 12114 HT:12000 -> ∘
·‖ B5: @ 12134 HT:12000 -> ▶ 12000
·‖ 30: @ 12146 HT:12000 -> ∘
·‖ B5: @ 12161 HT:12000 -> ▶ 12000
·‖ 30: @ 12177 HT:12000 -> ∘
·‖ B5: @ 12184 HT:12000 -> ▶ 12000
·‖ 30: @ 12212 HT:12000 -> ∘
·‖ 30: @ 12242 HT:13000 -> ▶ 12000
!◆! B5: calc(i=47, lev:12)
!◆! B5: calc(i=51, lev:13)
!◆! 30: calc(i=45, lev:12)
!◆! 30: calc(i=50, lev:13)
!◆! 30: calc(i=56, lev:14)
·‖ B5: @ 13074 HT:13000 -> ▶ 13000
·‖ B5: @ 13112 HT:13000 -> ▶ 13000
!◆! B5: calc(i=54, lev:13)
!◆! B5: calc(i=59, lev:14)
·‖ B5: @ 13228 HT:13000 -> ▶ 13000
!◆! B5: calc(i=52, lev:13)
!◆! B5: calc(i=58, lev:14)
!◆! B5: calc(i=62, lev:15)
·‖ B5: @ 13370 HT:13000 -> ▶ 13000
·‖ B5: @ 13392 HT:14000 -> ▶ 13000
·‖ B5: @ 14072 HT:14000 -> ▶ 14000
!◆! B5: calc(i=57, lev:14)
!◆! B5: calc(i=61, lev:15)
·‖ B5: @ 14197 HT:14000 -> ▶ 14000
!◆! B5: calc(i=55, lev:14)
!◆! B5: calc(i=60, lev:15)
!◆! B5: calc(i=63, lev:16)
·‖ B5: @ 14335 HT:14000 -> ▶ 14000
·‖ B5: @ 14358 HT:14000 -> ▶ 14000
·‖ B5: @ 14380 HT:15000 -> ▶ 14000
·‖ B5: @ 15075 HT:15000 -> ▶ 15000
·‖ B5: @ 15108 HT:15000 -> ▶ 15000
·‖ B5: @ 15130 HT:16000 -> ▶ 15000
·‖ B5: @ 16073 HT:17000 -> ▶ 16000
·‖ B5: @ 17073 HT:55843 -> ▶ 17000
#--◆--# offset() ? = 18790
#--◆--# testLoad.getHash() ? = 5982496738762178821
‖▽▼▽‖ D9: @ 18649
‖▽▼▽‖ 7F: @ 18717
‖▽▼▽‖ 8D: @ 20825
‖▽▼▽‖ F8: @ 20915
‖▽▼▽‖ 77: @ 20905
‖▽▼▽‖ 30: @ 37252
‖▽▼▽‖ AF: @ 37390
‖▽▼▽‖ B5: @ 55965