Why does NetBSD grep slow down nearly 15x on subsequent calls

Question

I'm working through examples in APUE. On a NetBSD 9.0 system, under no major load, I time a call to grep and get an unremarkable result:

apue$ cd /usr/include
apue$ time -p grep __POSIX_SOURCE */*.h > /dev/null
real         0.73
user         0.01
sys          0.63

However, if I repeat the experiment several times, the system time spikes drastically (up to 15x):

apue$ time -p grep _POSIX_SOURCE */*.h > /dev/null
real         0.57
user         0.02
sys          0.54
apue$ time -p grep _POSIX_SOURCE */*.h > /dev/null
real        10.06
user         0.01
sys         10.04
apue$ time -p grep _POSIX_SOURCE */*.h > /dev/null
real         3.57
user         0.01
sys          3.56
apue$ time -p grep _POSIX_SOURCE */*.h > /dev/null
real         4.58
user         0.00
sys          4.58
apue$ time -p grep _POSIX_SOURCE */*.h > /dev/null
real         5.56
user         0.02
sys          5.53
apue$ time -p grep _POSIX_SOURCE */*.h > /dev/null
real         6.57
user         0.00
sys          6.56
apue$ time -p grep _POSIX_SOURCE */*.h > /dev/null
real         2.56
user         0.01
sys          2.54

Is this expected behavior? What could be causing such wide variance?

Update Based on the answer given by @Tim, I took a look at my Buffercache, and saw that it was fully allocated at 100% when grep was struggling with my search. After restarting the VM, the buffer usage had dropped down to around 95%.

$ sysstat bufcache
                    /0   /1   /2   /3   /4   /5   /6   /7   /8   /9   /10
     Load Average   |

      603 metadata buffers using                5565 kBytes of memory ( 0%).
    15512 pages for cached file data using     62048 kBytes of memory ( 3%).
     3034 pages for executables using          12136 kBytes of memory ( 1%).
     6460 pages for anon (non-file) data       25840 kBytes of memory ( 1%).
   468172 free pages                         1872688 kBytes of memory (93%).

File System          Bufs used   %   kB in use   %  Bufsize kB   %  Util %
/                          577  95        5378  97        5418  97      99

Total:                     577  95        5378  97        5418  97      99

Answer 1

Could it be that you are exhausting the read cache (File System Buffer Cache; ref. buffercache(9))?

On the first pass the cache is mainly empty, so pages are just being added. Once the cache is full, some sort of LRU (least recently used) algorithm needs to be executed in order to work out what page(s) need to be evicted from the cache. It takes (additional) time for that code to do its job.

Monitor the state of your memory while you perform these tests to see if the slowdown coincides with free memory reaching zero.