Hi *,

i have had similar observations (see eMail to current-users with subject 
  "ps crawling...").

My system is also a larger main memory system (1GB). I observed some
unsusual things last night comparable to Patrik's findings.
Here is a list:
- I found pagedaemon running wild for some time so the top
   showed 98% CPU usage.
- vmstat bufs is high cpu and cannot keep up with the usual display interval
- ps take about 100ms per process (it is faster shortly after re-boot)

- ps has system times in the > 98% range (it takes about 15s system time).

Could this be related to the other thread in -current lately about
pmap 0 showing many memory segments/fragmentation ?

A kdump -R of "ps alxww" looks as follows during the listing loop:

   Note the ~25ms and ~75ms durations of the __sysctl() calls. The system
   was otherwise idle. The time seems to be actually burned in kernel mode.

   6995 ps       0.000098 CALL  write(0x1,134701056,96)
   6995 ps       0.000300 GIO   fd 1 wrote 96 bytes
        "    0  1209     1  11   3   0    52   680 ttyin    Ss+  E2 
0:00.01 /us\
         r/libexec/getty Pc ttyE2
        "
   6995 ps       0.000157 RET   write 96/0x60
   6995 ps       0.000152 CALL  __sysctl(0xbfbfeae0,0x5,0,0xbfbfe8ac,0,0)
   6995 ps       0.000186 RET   __sysctl 0
   6995 ps       0.000005 CALL 
__sysctl(0xbfbfeae0,0x5,134635520,0xbfbfe8ac,0,0)
   6995 ps       0.000206 RET   __sysctl 0
   6995 ps       0.000031 CALL 
__sysctl(0xbfbfeab0,0x4,0xbfbfeaa8,0xbfbfeaac,0,0
)
   6995 ps       0.025983 RET   __sysctl 0
   6995 ps       0.000297 CALL 
__sysctl(0xbfbfeab0,0x4,134770688,0xbfbfeaac,0,0)
   6995 ps       0.077120 RET   __sysctl 0
   6995 ps       0.000051 CALL  write(0x1,134701056,96)
   6995 ps       0.000299 GIO   fd 1 wrote 96 bytes
        "    0   334     1  11   3   0    52   680 ttyin    Ss+  E3 
0:00.00 /us\
         r/libexec/getty Pc ttyE3
        "
   6995 ps       0.000158 RET   write 96/0x60
   6995 ps       0.000152 CALL  __sysctl(0xbfbfeae0,0x5,0,0xbfbfe8ac,0,0)
   6995 ps       0.000166 RET   __sysctl 0
   6995 ps       0.003067 CALL 
__sysctl(0xbfbfeae0,0x5,134635520,0xbfbfe8ac,0,0)
   6995 ps       0.000305 RET   __sysctl 0
   6995 ps       0.000040 CALL 
__sysctl(0xbfbfeab0,0x4,0xbfbfeaa8,0xbfbfeaac,0,0
)
   6995 ps       0.025922 RET   __sysctl 0
   6995 ps       0.000295 CALL 
__sysctl(0xbfbfeab0,0x4,134770688,0xbfbfeaac,0,0)
   6995 ps       0.077110 RET   __sysctl 0
   6995 ps       0.000140 CALL  write(0x1,134701056,96)
   6995 ps       0.000302 GIO   fd 1 wrote 96 bytes
        "    0   336     1  11   3   0    52   680 ttyin    Ss+  E4 
0:00.01 /us\
         r/libexec/getty Pc ttyE4
        "
   6995 ps       0.000157 RET   write 96/0x60
   6995 ps       0.000144 CALL  __sysctl(0xbfbfeae0,0x5,0,0xbfbfe8ac,0,0)
   6995 ps       0.000164 RET   __sysctl 0
   6995 ps       0.000005 CALL 
__sysctl(0xbfbfeae0,0x5,134635520,0xbfbfe8ac,0,0)
   6995 ps       0.000009 RET   __sysctl 0
   6995 ps       0.000028 CALL 
__sysctl(0xbfbfeab0,0x4,0xbfbfeaa8,0xbfbfeaac,0,0
)
   6995 ps       0.025861 RET   __sysctl 0
   6995 ps       0.000304 CALL 
__sysctl(0xbfbfeab0,0x4,134770688,0xbfbfeaac,0,0)
   6995 ps       0.077255 RET   __sysctl 0
   6995 ps       0.000057 CALL  write(0x1,134701056,96)
   6995 ps       0.000299 GIO   fd 1 wrote 96 bytes
        "    0   337     1  11   3   0    52   680 ttyin    Ss+  E5 
0:00.01 /us\
         r/libexec/getty Pc ttyE5
        "
   6995 ps       0.000158 RET   write 96/0x60
   6995 ps       0.000208 CALL  exit(0)

Patrick Welche wrote:
> I just upgraded the kernel of an i386 box from
> NetBSD 1.6ZH (QUARTZ) #380: Tue Jan 20 11:50:29 GMT 2004
> to
> NetBSD 1.6ZI (QUARTZ) #382: Tue Feb  3 16:49:50 GMT 2004
> 
> and it is now so slow as to be practically unusable (eg overnight small
> database dump took 1h10m instead of 10m, I can watch the delay in the
> characters appearing - it is as if I were on a slow modem rather than
> on a keyboard plugged in the back).
>