From 439c171b6a2c7099b97500bededc51da6834fac5 Mon Sep 17 00:00:00 2001 From: Axel Gembe Date: Thu, 9 Nov 2023 21:58:26 +0700 Subject: [PATCH 1/3] spl-time: Use KeQueryPerformanceCounter instead of KeQueryTickCount `KeQueryTickCount` seems to only have a 15.625ms resolution unless the interrupt timer frequency is increased, which should be avoided due to power usage. Instead, this switches the `zfs_lbolt`, `gethrtime` and `random_get_bytes` to use `KeQueryPerformanceCounter`. On my system this gives a 100ns resolution. Signed-off-by: Axel Gembe --- module/os/windows/spl/spl-time.c | 27 +++++++++------------------ 1 file changed, 9 insertions(+), 18 deletions(-) diff --git a/module/os/windows/spl/spl-time.c b/module/os/windows/spl/spl-time.c index 94c5ed51da90..e41151ff7d40 100644 --- a/module/os/windows/spl/spl-time.c +++ b/module/os/windows/spl/spl-time.c @@ -37,20 +37,12 @@ * origin. Hence its primary use is to specify intervals. */ -static hrtime_t -zfs_abs_to_nano(uint64_t elapsed) -{ - return (elapsed * KeQueryTimeIncrement() * 100); -} - /* Open Solaris lbolt is in hz */ uint64_t zfs_lbolt(void) { uint64_t lbolt_hz; - LARGE_INTEGER ticks; - KeQueryTickCount(&ticks); - lbolt_hz = ticks.QuadPart * KeQueryTimeIncrement(); + lbolt_hz = gethrtime() / 100; lbolt_hz /= (10000000 / 119); // Solaris hz ? return (lbolt_hz); } @@ -59,14 +51,13 @@ hrtime_t gethrtime(void) { static LARGE_INTEGER start = { 0 }; + static LARGE_INTEGER freq = { 0 }; LARGE_INTEGER now; if (start.QuadPart == 0) { - KeQueryTickCount(&start); - start.QuadPart--; + start = KeQueryPerformanceCounter(&freq); } - KeQueryTickCount(&now); - ASSERT((now.QuadPart != start.QuadPart)); - return (zfs_abs_to_nano(now.QuadPart - start.QuadPart)); + now = KeQueryPerformanceCounter(NULL); + return (now.QuadPart - start.QuadPart) * (NANOSEC / freq.QuadPart); } /* @@ -76,21 +67,21 @@ gethrtime(void) int random_get_bytes(uint8_t *ptr, uint32_t len) { - LARGE_INTEGER TickCount; + LARGE_INTEGER PerfCounter; ULONG r; PULONG b; int i; - KeQueryTickCount(&TickCount); + PerfCounter = KeQueryPerformanceCounter(NULL); b = (PULONG) ptr; for (i = 0; i < len / sizeof (ULONG); i++) - b[i] = RtlRandomEx(&TickCount.LowPart); + b[i] = RtlRandomEx(&PerfCounter.LowPart); len &= (sizeof (ULONG) - 1); if (len > 0) { - r = RtlRandomEx(&TickCount.LowPart); + r = RtlRandomEx(&PerfCounter.LowPart); RtlCopyMemory(&b[i], &r, len); } return (0); From c318c7373c4ba03fc795d45ad74928dc931054e1 Mon Sep 17 00:00:00 2001 From: Axel Gembe Date: Fri, 10 Nov 2023 09:20:18 +0700 Subject: [PATCH 2/3] spl-time: Add assertion to gethrtime and cache NANOSEC / freq division One less division for each call. Signed-off-by: Axel Gembe --- module/os/windows/spl/spl-time.c | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/module/os/windows/spl/spl-time.c b/module/os/windows/spl/spl-time.c index e41151ff7d40..e3ad3668a91a 100644 --- a/module/os/windows/spl/spl-time.c +++ b/module/os/windows/spl/spl-time.c @@ -55,9 +55,12 @@ gethrtime(void) LARGE_INTEGER now; if (start.QuadPart == 0) { start = KeQueryPerformanceCounter(&freq); + ASSERT(freq.QuadPart < NANOSEC); + ASSERT(freq.QuadPart > 0); + freq.QuadPart = NANOSEC / freq.QuadPart; } now = KeQueryPerformanceCounter(NULL); - return (now.QuadPart - start.QuadPart) * (NANOSEC / freq.QuadPart); + return ((now.QuadPart - start.QuadPart) * freq.QuadPart); } /* From b5e06309eb397b84740541045345ec860f72a5cf Mon Sep 17 00:00:00 2001 From: Axel Gembe Date: Thu, 9 Nov 2023 19:47:05 +0700 Subject: [PATCH 3/3] vflush: Print reclaim statistics This shows how many reclaims have been processed in thousand increments and also how many reclaims are processed per second. Signed-off-by: Axel Gembe --- module/os/windows/spl/spl-vnode.c | 38 +++++++++++++++++++++++++++++-- 1 file changed, 36 insertions(+), 2 deletions(-) diff --git a/module/os/windows/spl/spl-vnode.c b/module/os/windows/spl/spl-vnode.c index 4a5480dc2b2a..6103e1632ebb 100644 --- a/module/os/windows/spl/spl-vnode.c +++ b/module/os/windows/spl/spl-vnode.c @@ -1537,6 +1537,37 @@ mount_count_nodes(struct mount *mp, int flags) return (count); } +static void +print_reclaim_stats(boolean_t init, int reclaims) +{ + static int last_reclaims = 0; + int reclaims_delta; + int reclaims_per_second; + static hrtime_t last_stats_time = 0; + hrtime_t last_stats_time_delta; + + if (init) { + last_stats_time = gethrtime(); + return; + } + + if ((reclaims % 1000) != 0) { + return; + } + + reclaims_delta = reclaims - last_reclaims; + last_stats_time_delta = gethrtime() - last_stats_time; + + reclaims_per_second = (((int64_t)reclaims_delta) * NANOSEC) / + MAX(last_stats_time_delta, 1); + + dprintf("%s: %d reclaims processed (%d/s).\n", __func__, reclaims, + reclaims_per_second); + + last_reclaims = reclaims; + last_stats_time = gethrtime(); +} + /* * Let's try something new. If we are to vflush, lets do everything we can @@ -1567,6 +1598,8 @@ vflush(struct mount *mp, struct vnode *skipvp, int flags) mutex_enter(&vnode_all_list_lock); filesanddirs: + print_reclaim_stats(B_TRUE, 0); + while (1) { for (rvp = list_head(&vnode_all_list); rvp; @@ -1668,6 +1701,7 @@ vflush(struct mount *mp, struct vnode *skipvp, int flags) if (!isbusy) { reclaims++; + print_reclaim_stats(B_FALSE, reclaims); break; // must restart loop if unlinked node } } @@ -1684,8 +1718,8 @@ vflush(struct mount *mp, struct vnode *skipvp, int flags) mutex_exit(&vnode_all_list_lock); - if (mp == NULL && reclaims > 0) { - dprintf("%s: %llu reclaims processed.\n", __func__, reclaims); + if (reclaims > 0) { + dprintf("%s: %d reclaims processed.\n", __func__, reclaims); }