memory/gc/test/test_hook.py::TestIncMiniMarkHooks::()::test_on_gc_collect

self = <rpython.memory.gc.test.test_hook.TestIncMiniMarkHooks object at 0x0000017ba2346640>

    def test_on_gc_collect(self):
        from rpython.memory.gc import incminimark as m
        self.gc.hooks._gc_collect_step_enabled = True
        self.gc.hooks._gc_collect_enabled = True
        self.malloc(S)
        self.gc.collect()
        assert self.gc.hooks.steps == [
            {'oldstate': m.STATE_SCANNING, 'newstate': m.STATE_MARKING},
            {'oldstate': m.STATE_MARKING, 'newstate': m.STATE_SWEEPING},
            {'oldstate': m.STATE_SWEEPING, 'newstate': m.STATE_FINALIZING},
            {'oldstate': m.STATE_FINALIZING, 'newstate': m.STATE_SCANNING}
        ]
        assert self.gc.hooks.collects == [
            {'num_major_collects': 1,
             'arenas_count_before': 0,
             'arenas_count_after': 0,
             'arenas_bytes': 0,
             'rawmalloc_bytes_after': 0,
             'rawmalloc_bytes_before': 0,
             'pinned_objects': 0,
            }
            ]
        assert len(self.gc.hooks.durations) == 4 # 4 steps
        for d in self.gc.hooks.durations:
>           assert d > 0.0
E           assert 0.0 > 0.0

memory\gc\test\test_hook.py:110: AssertionError
---------- Captured stderr setup ----------
[c5f019efb41c680] {gc-set-nursery-size
nursery size: 256 
[c5f019efb41c680] gc-set-nursery-size}
---------- Captured stderr call ----------
[c5f019efb510900] {gc-minor
[c5f019efb510900] {gc-minor-walkroots
[c5f019efb510900] gc-minor-walkroots}
minor collect, total memory used: 0 
number of pinned objects: 0 
total size of surviving objects: 0 
time taken: 0.000999927520752 
[c5f019efb58aa00] gc-minor}
[c5f019efb58aa00] {gc-collect-step
starting gc state:  SCANNING 
stopping, now in gc state:  MARKING 
time taken:  0.0 
[c5f019efb604b80] gc-collect-step}
[c5f019efb604b80] {gc-minor
[c5f019efb604b80] {gc-minor-walkroots
[c5f019efb604b80] gc-minor-walkroots}
minor collect, total memory used: 0 
number of pinned objects: 0 
total size of surviving objects: 0 
time taken: 0.0 
[c5f019efb604b80] gc-minor}
[c5f019efb604b80] {gc-collect-step
starting gc state:  MARKING 
number of objects to mark 0 plus 0 
stopping, now in gc state:  SWEEPING 
time taken:  0.000999927520752 
[c5f019efb67ec80] gc-collect-step}
[c5f019efb67ec80] {gc-minor
[c5f019efb67ec80] {gc-minor-walkroots
[c5f019efb67ec80] gc-minor-walkroots}
minor collect, total memory used: 0 
number of pinned objects: 0 
total size of surviving objects: 0 
time taken: 0.000999927520752 
[c5f019efb6f8d80] gc-minor}
[c5f019efb6f8d80] {gc-collect-step
starting gc state:  SWEEPING 
freeing GC objects, up to 6 pages. No more pages left. 
[c5f019efb6f8d80] {gc-collect-done
arenas:                0  =>  0 
bytes used in arenas:  0 
bytes raw-malloced:    0  =>  0 
next major collection threshold:  640.0 
[c5f019efb6f8d80] gc-collect-done}
stopping, now in gc state:  FINALIZING 
time taken:  0.0 
[c5f019efb6f8d80] gc-collect-step}
[c5f019efb6f8d80] {gc-minor
[c5f019efb772e80] {gc-minor-walkroots
[c5f019efb772e80] gc-minor-walkroots}
minor collect, total memory used: 0 
number of pinned objects: 0 
total size of surviving objects: 0 
time taken: 0.000999927520752 
[c5f019efb772e80] gc-minor}
[c5f019efb772e80] {gc-collect-step
starting gc state:  FINALIZING 
stopping, now in gc state:  SCANNING 
time taken:  0.00100016593933 
[c5f019efb7ed000] gc-collect-step}

builder: rpython-win-x86-64 build #439+

test: memory/gc/test/test_hook.py::TestIncMiniMarkHooks::()::test_on_gc_collect