Table of Contents

Statistical profiling

Minix 3 supports statistical profiling. It is available in two versions. The basic one is based on BIOS RTC interrupts. This is available on any x86 machine and in virtual machines. As interrupts are not enabled in kernel this method does not make kernel profiling possible. The second method is using non-maskable interrupts (NMI) which also interrupt the kernel. This requires APIC mode. The NMIs are generated using performance counters. Each platform provides different counters, therefore Minix has to support each platform separately.

Prerequisites

Before statistical profiling can be used, some configuration changes must be made in MINIX. In /usr/src/minix/include/minix/config.h, set the SPROFILE constant to 1. This causes the kernel to allocate a huge buffer to store profiling samples. After these changes, a make build command (in /usr/src) is needed to compile and install the new image.

If you want to use NMI rather than RTC, you need to perform the build with the following make variables (TODO: explain how to set those):

MKAPIC=1
MKACPI=1
MKWATCHDOG=1

After the build process has installed the system with these new settings, you must also pass some kernel parameters from the bootloader to make this work. Edit /boot.cfg to add a menu item that includes the following arguments: watchdog=1 no_apic=0 acpi=yes. Note that /boot.cfg is overwritten when the system is compiled, so it may be more convenient to change the local additions file /etc/boot.cfg.local, that is never overwritten, instead. After booting this new option, NMI statistical profiling should work.

Usage

profiling is started and stopped using the profile utility, collected result are written in a file. Use sprofalyze script to process the data and visualize the results.

Statistical Profiling:
  profile start [--rtc | --nmi] [-m memsize] [-o outfile] [-f frequency]
  profile stop

   --rtc is default, --nmi allows kernel profiling
Call Profiling:
  profile get   [-m memsize] [-o outfile]
  profile reset

   - memsize in MB, default: 64
   - default output file: profile.{stat|call}.out
   - sample frequencies for --rtc (default: 6):
      3    8192 Hz          10     64 Hz
      4    4096 Hz          11     32 Hz
      5    2048 Hz          12     16 Hz
      6    1024 Hz          13      8 Hz
      7     512 Hz          14      4 Hz
      8     256 Hz          15      2 Hz
      9     128 Hz

NMI mode

When using NMI more any frequncy may be specified in Hz, e.g. -f 10000 for 10kHz.

Beware, if no frequency is specified 6 is taken as default which in case of NMI means 6Hz!

Suported platforms:

Sample sprofalyze output

================================================================================
Data file: profile.stat.out
================================================================================

  System process ticks:      19935 ( 51%)
    User process ticks:      15339 ( 39%)          Details of system process
       Idle time ticks:       3690 ( 10%)          samples, aggregated and
                        ----------  ----           per process, are below.
           Total ticks:      38964 (100%)

--------------------------------------------------------------------------------
Total system process time                                          19935 samples
--------------------------------------------------------------------------------
  kernel                       _ipc_entry *****                             5.6%
  kernel                        _read_tsc ****                              4.6%
  kernel          ___switch_address_space ***                               3.9%
  kernel                       _phys_copy ***                               3.9%
  kernel               _kernel_call_entry ***                               3.8%
  kernel                     _isokendpt_f ***                               3.6%
  kernel                    _context_stop ***                               3.5%
  kernel                     _read_tsc_64 **                                2.4%
  kernel                  _switch_to_user **                                2.4%
  kernel                          _do_ipc **                                2.3%
      vm                 __do_kernel_call **                                2.2%
  kernel            _restore_user_context **                                1.8%
  kernel                           _sub64 **                                1.8%
  kernel                       fill_start **                                1.7%
  kernel                _copy_msg_to_user **                                1.6%
  kernel             _lapic_restart_timer *                                 1.4%
     vfs                         _release *                                 1.4%
     mfs                      _search_dir *                                 1.3%
     mfs                        __receive *                                 1.3%
     vfs                        __sendrec *                                 1.1%
  kernel                  _virtual_copy_f *                                 1.1%
  kernel                       _mini_send *                                 1.1%
     mfs                           __send *                                 1.1%
     mfs                       _get_block *                                 1.1%
  kernel                    _lin_lin_copy *                                 1.0%
                             <1% *******************************  43.0%
--------------------------------------------------------------------------------
total                                                                     100.0%

--------------------------------------------------------------------------------
kernel                                           59.3% of system process samples
--------------------------------------------------------------------------------
                      _ipc_entry **************************                 9.4%
                       _read_tsc **********************                     7.8%
         ___switch_address_space *******************                        6.6%
                      _phys_copy ******************                         6.5%
              _kernel_call_entry ******************                         6.4%
                    _isokendpt_f *****************                          6.0%
                   _context_stop *****************                          5.9%
                    _read_tsc_64 ************                               4.1%
                 _switch_to_user ************                               4.0%
                         _do_ipc ***********                                3.9%
           _restore_user_context *********                                  3.1%
                          _sub64 *********                                  3.0%
                      fill_start ********                                   2.9%
               _copy_msg_to_user ********                                   2.7%
            _lapic_restart_timer *******                                    2.3%
                 _virtual_copy_f ******                                     1.9%
                      _mini_send ******                                     1.8%
                   _lin_lin_copy *****                                      1.7%
                        _enqueue ****                                       1.4%
                        _dequeue ****                                       1.4%
             _copy_msg_from_user ****                                       1.3%
                      _createpde ****                                       1.2%
                             <1% ****************************************  14.7%
--------------------------------------------------------------------------------
kernel                                                                    100.0%

--------------------------------------------------------------------------------
vm                                               15.0% of system process samples
--------------------------------------------------------------------------------
                __do_kernel_call ****************************************  14.6%
            _pt_ptalloc_in_range ******************                         6.5%
                   __kernel_call ***************                            5.4%
                    _pt_writemap **************                             5.2%
                      _slaballoc **************                             5.1%
                _physr_incr_iter *************                              4.6%
                   _physr_remove **********                                 3.7%
                   _physr_insert **********                                 3.5%
                       __receive **********                                 3.4%
                 _map_ph_writept *******                                    2.4%
                         _pt_new ******                                     2.2%
                       _slabfree ******                                     2.0%
                   _physr_search ******                                     2.0%
                        _pt_free *****                                      1.8%
         _physr_start_iter_least *****                                      1.7%
                    _addr_insert *****                                      1.7%
                    _addr_remove *****                                      1.6%
                        _do_fork *****                                      1.6%
                           _main ****                                       1.5%
                       _objstats ****                                       1.4%
                     _map_lookup ****                                       1.4%
                   _vm_isokendpt ****                                       1.4%
                    _addr_search ****                                       1.3%
                      _sys_vmctl ****                                       1.3%
                          __send ****                                       1.2%
                _addr_start_iter ****                                       1.2%
                    _map_writept ****                                       1.2%
                         _map_pf ***                                        1.1%
              _map_new_physblock ***                                        1.1%
                    _map_subfree ***                                        1.0%
                 _physr_get_iter ***                                        1.0%
                             <1% ****************************************  14.9%
--------------------------------------------------------------------------------
vm                                                                        100.0%