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

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

    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 ----------
[c581b5ee398f100] {gc-set-nursery-size
nursery size: 256 
[c581b5ee3a09200] gc-set-nursery-size}
---------- Captured stderr call ----------
[c581b5ee3afd480] {gc-minor
[c581b5ee3bf1700] {gc-minor-walkroots
[c581b5ee3c6b800] gc-minor-walkroots}
minor collect, total memory used: 0 
number of pinned objects: 0 
total size of surviving objects: 0 
time taken: 0.00300002098083 
[c581b5ee3c6b800] gc-minor}
[c581b5ee3c6b800] {gc-collect-step
starting gc state:  SCANNING 
stopping, now in gc state:  MARKING 
time taken:  0.00200009346008 
[c581b5ee3d5fa80] gc-collect-step}
[c581b5ee3d5fa80] {gc-minor
[c581b5ee3d5fa80] {gc-minor-walkroots
[c581b5ee3dd9b80] gc-minor-walkroots}
minor collect, total memory used: 0 
number of pinned objects: 0 
total size of surviving objects: 0 
time taken: 0.000999927520752 
[c581b5ee3dd9b80] gc-minor}
[c581b5ee3dd9b80] {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 
[c581b5ee3e53c80] gc-collect-step}
[c581b5ee3e53c80] {gc-minor
[c581b5ee3ecdd80] {gc-minor-walkroots
[c581b5ee3ecdd80] gc-minor-walkroots}
minor collect, total memory used: 0 
number of pinned objects: 0 
total size of surviving objects: 0 
time taken: 0.00200009346008 
[c581b5ee3f47f00] gc-minor}
[c581b5ee3f47f00] {gc-collect-step
starting gc state:  SWEEPING 
freeing GC objects, up to 6 pages. No more pages left. 
[c581b5ee3fc2000] {gc-collect-done
arenas:                0  =>  0 
bytes used in arenas:  0 
bytes raw-malloced:    0  =>  0 
next major collection threshold:  640.0 
[c581b5ee3fc2000] gc-collect-done}
stopping, now in gc state:  FINALIZING 
time taken:  0.000999927520752 
[c581b5ee3fc2000] gc-collect-step}
[c581b5ee3fc2000] {gc-minor
[c581b5ee3fc2000] {gc-minor-walkroots
[c581b5ee403c100] gc-minor-walkroots}
minor collect, total memory used: 0 
number of pinned objects: 0 
total size of surviving objects: 0 
time taken: 0.000999927520752 
[c581b5ee40b6280] gc-minor}
[c581b5ee40b6280] {gc-collect-step
starting gc state:  FINALIZING 
stopping, now in gc state:  SCANNING 
time taken:  0.0 
[c581b5ee4130380] gc-collect-step}

builder: rpython-win-x86-64 build #400

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