Subject: NWSCONS - some profiling data
To: None <current-users@netbsd.org>
From: None <drochner@zel459.zel.kfa-juelich.de>
List: current-users
Date: 12/18/1998 21:06:32
I'd like to make wscons ready to become the default terminal
driver on i386. While it is virtually impossible to combine
the features os pcvt with size and speed of pcccons, it should
be possible to get a reasonable tradeoff.
I hope the serious bugs are worked out, but performance is still
not to everyone's satisfaction, some people complained about absymal
performance on their hardware.
To find what causes this it would be really good if you could do some
kernel profiling. This is not hard at all:
- compile and boot a profiling kernel (config -p <CONFIG>)
- kgmon -b [start profiling]
- <run some stuff>
- kgmon -h [stop profiling]
- kgmon -p [writes data to "gmon.out"]
- kgmon -r [reset for next measurement]
- gprof /netbsd >gprof.out [convert to human readable]

The data below are collected on a system I'd call average: Pentium200/MMX
with an S3 based VGA board.
I've tried two different profiles:
- run "od /netbsd" a couple of times
  This stresses in plain character output and scrolling.
- run "/usr/games/worms" for some minutes
  This causes more control sequence processing in the vt100 emulator.

"worms" is actually so fast that one can't make sense of
the displayed characters - it should get some timing control
to be "useful" in the future.

My data are of course a random sample only, the absolute numbers
are not worth much. But if you get a result where a function
needs relatively much more time, then it would be nice if
you'd report it.

best regards
Matthias


The "od" case:

  %   cumulative   self              self     total           
 time   seconds   seconds    calls  ms/call  ms/call  name    
[...]
  8.4     112.38    13.50 38896203     0.00     0.00  _pcdisplay_putchar [18]
  8.3     125.67    13.29 38896203     0.00     0.00  
_wsemul_vt100_output_normal [14]
  6.2     135.63     9.96   609761     0.02     0.02  _vga_copyrows [19]
  2.6     139.73     4.10  1220010     0.00     0.00  _pcdisplay_cursor [20]
  2.3     143.41     3.68   610004     0.01     0.08  _wsemul_vt100_output [13]
  2.2     147.02     3.61   609761     0.01     0.01  _pcdisplay_eraserows [21]
[...]
  0.3     154.99     0.45   610004     0.00     0.08  _wsdisplaystart [12]
[...]
  0.3     156.26     0.41   609761     0.00     0.02  _wsemul_vt100_scrollup 
[16]
[...]
  0.2     158.35     0.26  1219648     0.00     0.01  
_wsemul_vt100_output_c0c1 [15]

The "worms" case:

  %   cumulative   self              self     total           
 time   seconds   seconds    calls  ms/call  ms/call  name    
[...]
  8.5      55.69    11.28 54093804     0.00     0.00  _wsemul_vt100_output_csi 
[14]
  6.9      64.84     9.15  1658229     0.01     0.03  _wsemul_vt100_output [12]
  5.6      72.25     7.41  3316647     0.00     0.00  _pcdisplay_cursor [18]
[...]
  3.6      92.45     4.71  9790689     0.00     0.00  _wsemul_vt100_handle_csi 
[21]
  3.0      96.40     3.95  9788373     0.00     0.00  
_wsemul_vt100_output_normal [17]
  2.9     100.21     3.81  9788373     0.00     0.00  _pcdisplay_putchar [22]
  2.5     103.58     3.37  9790689     0.00     0.00  _wsemul_vt100_output_esc 
[23]
[...]
  1.0     118.97     1.27  9790695     0.00     0.00  
_wsemul_vt100_output_c0c1 [28]