PageStorage GC may not able to cleanup as expected under heavy update workload #2382
Description
From the logs below, we can see that the GC move forward.
However, under a heavy insert/update workload, the number of files left on disk remains around 1000, the number of legacy files remains around 300. Sometimes it takes a long time (around 30 seconds) to run a round of GC.
That is not as expected, we want to keep the number of legacy files around 100. It causes useless read flow / read operations / memory footprint for running GC. Need further investigation.
[2021/07/10 18:55:45.000 +08:00] [INFO] [<unknown>] ["PageStorage: db_53.t_55.log GC exit within 7.73 sec. PageFiles from [2632,0,Checkpoint] to [3595,0,Formal], num files: 967, num legacy:277, compact legacy archive files: 6, remove data files: 1, gc apply: 0 puts and 0 refs and 0 deletes and 2215 upserts"] [thread_id=5]
[2021/07/10 18:56:50.691 +08:00] [INFO] [<unknown>] ["PageStorage: db_53.t_55.log GC exit within 7.87 sec. PageFiles from [2636,0,Checkpoint] to [3597,0,Formal], num files: 965, num legacy:273, compact legacy archive files: 0, remove data files: 4, gc apply: 0 puts and 0 refs and 0 deletes and 2215 upserts"] [thread_id=32]
[2021/07/10 18:57:55.339 +08:00] [INFO] [<unknown>] ["PageStorage: db_53.t_55.log GC exit within 8.14 sec. PageFiles from [2636,0,Checkpoint] to [3600,0,Formal], num files: 969, num legacy:277, compact legacy archive files: 7, remove data files: 3, gc apply: 0 puts and 0 refs and 0 deletes and 2216 upserts"] [thread_id=32]
[2021/07/10 18:59:00.758 +08:00] [INFO] [<unknown>] ["PageStorage: db_53.t_55.log GC exit within 7.83 sec. PageFiles from [2640,0,Checkpoint] to [3601,0,Formal], num files: 965, num legacy:274, compact legacy archive files: 0, remove data files: 8, gc apply: 0 puts and 0 refs and 0 deletes and 2216 upserts"] [thread_id=6]
[2021/07/10 18:59:56.500 +08:00] [INFO] [<unknown>] ["PageStorage: db_53.t_55.log GC exit within 0.54 sec. PageFiles from [2640,0,Checkpoint] to [3603,0,Formal], num files: 968, num legacy:282, compact legacy archive files: 9, remove data files: 1, gc apply: 0 puts and 0 refs and 0 deletes and 0 upserts"] [thread_id=36]
[2021/07/10 19:01:03.358 +08:00] [INFO] [<unknown>] ["PageStorage: db_53.t_55.log GC exit within 0.41 sec. PageFiles from [2646,0,Checkpoint] to [3605,0,Formal], num files: 962, num legacy:275, compact legacy archive files: 0, remove data files: 0, gc apply: 0 puts and 0 refs and 0 deletes and 0 upserts"] [thread_id=43]
[2021/07/10 19:02:09.261 +08:00] [INFO] [<unknown>] ["PageStorage: db_53.t_55.log GC exit within 0.41 sec. PageFiles from [2646,0,Checkpoint] to [3608,0,Formal], num files: 965, num legacy:275, compact legacy archive files: 0, remove data files: 0, gc apply: 0 puts and 0 refs and 0 deletes and 0 upserts"] [thread_id=39]
[2021/07/10 19:03:16.054 +08:00] [INFO] [<unknown>] ["PageStorage: db_53.t_55.log GC exit within 0.39 sec. PageFiles from [2646,0,Checkpoint] to [3610,0,Formal], num files: 967, num legacy:275, compact legacy archive files: 0, remove data files: 0, gc apply: 0 puts and 0 refs and 0 deletes and 0 upserts"] [thread_id=6]
[2021/07/10 19:04:39.478 +08:00] [INFO] [<unknown>] ["PageStorage: db_53.t_55.log GC exit within 11.79 sec. PageFiles from [2646,0,Checkpoint] to [3613,0,Formal], num files: 970, num legacy:275, compact legacy archive files: 0, remove data files: 16, gc apply: 0 puts and 0 refs and 0 deletes and 0 upserts"] [thread_id=32]
[2021/07/10 19:05:48.790 +08:00] [INFO] [<unknown>] ["PageStorage: db_53.t_55.log GC exit within 20.81 sec. PageFiles from [2646,0,Checkpoint] to [3615,0,Formal], num files: 972, num legacy:291, compact legacy archive files: 0, remove data files: 0, gc apply: 0 puts and 0 refs and 0 deletes and 2215 upserts"] [thread_id=31]
[2021/07/10 19:06:52.359 +08:00] [INFO] [<unknown>] ["PageStorage: db_53.t_55.log GC exit within 17.29 sec. PageFiles from [2646,0,Checkpoint] to [3618,0,Formal], num files: 976, num legacy:291, compact legacy archive files: 0, remove data files: 8, gc apply: 0 puts and 0 refs and 0 deletes and 2214 upserts"] [thread_id=36]
[2021/07/10 19:07:44.068 +08:00] [INFO] [<unknown>] ["PageStorage: db_53.t_55.log GC exit within 9.78 sec. PageFiles from [2646,0,Checkpoint] to [3620,0,Formal], num files: 979, num legacy:299, compact legacy archive files: 10, remove data files: 10, gc apply: 0 puts and 0 refs and 0 deletes and 2214 upserts"] [thread_id=35]
[2021/07/10 19:08:47.362 +08:00] [INFO] [<unknown>] ["PageStorage: db_53.t_55.log GC exit within 8.04 sec. PageFiles from [2653,0,Checkpoint] to [3623,0,Formal], num files: 974, num legacy:300, compact legacy archive files: 19, remove data files: 2, gc apply: 0 puts and 0 refs and 0 deletes and 2214 upserts"] [thread_id=36]
[2021/07/10 19:09:41.776 +08:00] [INFO] [<unknown>] ["PageStorage: db_53.t_55.log GC exit within 0.45 sec. PageFiles from [2670,0,Checkpoint] to [3625,0,Formal], num files: 959, num legacy:284, compact legacy archive files: 0, remove data files: 0, gc apply: 0 puts and 0 refs and 0 deletes and 0 upserts"] [thread_id=30]
[2021/07/10 19:10:47.215 +08:00] [INFO] [<unknown>] ["PageStorage: db_53.t_55.log GC exit within 0.47 sec. PageFiles from [2670,0,Checkpoint] to [3628,0,Formal], num files: 962, num legacy:284, compact legacy archive files: 0, remove data files: 0, gc apply: 0 puts and 0 refs and 0 deletes and 0 upserts"] [thread_id=41]
[2021/07/10 19:11:51.599 +08:00] [INFO] [<unknown>] ["PageStorage: db_53.t_55.log GC exit within 0.48 sec. PageFiles from [2670,0,Checkpoint] to [3631,0,Formal], num files: 965, num legacy:284, compact legacy archive files: 0, remove data files: 0, gc apply: 0 puts and 0 refs and 0 deletes and 0 upserts"] [thread_id=30]