Enable Checkmk profiling

It is possible to profile the rendering process of Multisite pages. This is done using the Python module cProfile. For viewing the profiling data, we use snakeviz.

SnakeViz is a viewer for Python profiling data that runs as a web application in your browser. It is inspired by the wxPython profile viewer RunSnakeRun.

LAST TESTED ON CHECKMK 2.2.0P1

Table of Contents

Step-by-step guide

GUI Profiling

Don't use 'Enable profiling for all requests'. This option will profile a Multisite request randomly, and most of the time, it will be the slowest one.

.

Enable profiling in Checkmk

  1. SetupGeneralGlobal SettingsUser InterfaceProfile Request
    Screenshot of enable profiling by request via global settings.
    .
  2. Modify the URL to profile by adding '&_profile=1' and fire the request in your browser

    http://localhost/nagnis_master/check_mk/view.py?view_name=allhosts&_profile=1

    .

  3. Now two files are created in ~/var/check_mk/

    root@mylinuxhost:/opt/omd/sites/mysite/var/check_mk# ll |grep multisite
    -rw-rw---- 1 mysite mysite 100246 Nov 6 13:35 multisite.profile
    -rwxr-xr-x 1 mysite mysite 155 Nov 6 13:35 multisite.py*

    .

  4. By executing 'multisite.py', you can get runtime statistics about the last processed page.

    root@mylinuxhost:/opt/omd/sites/mysite/var/check_mk# ./multisite.py |more
    Fri Nov  6 13:35:33 2020    /omd/sites/nagnis_master/var/check_mk/multisite.profile
    
             9585 function calls (9480 primitive calls) in 0.007 seconds
    
       Ordered by: internal time
    
       ncalls  tottime  percall  cumtime  percall filename:lineno(function)
            1    0.001    0.001    0.002    0.002 /omd/sites/mysite/lib/python/cmk/gui/modules.py:140(_cmk_gui_top_level_modules)
         4652    0.000    0.000    0.000    0.000 {method 'startswith' of 'str' objects}
    ...
    ...

    .

  5. For viewing multisite. Profile with snakeviz, move the file to another directory (e.g., /tmp), and change the owner to the owner of your Internet Browser.

    linuxuser@mylinuxhost:/omd/sites/mysite/var/check_mk$ sudo cp multisite.profile /tmp/
    linuxuser@mylinuxhost:/tmp$ sudo chown linuxuser:linuxuser multisite.profile
    

    .

  6. Install the Python module (for Python 2 or Python 3, respectively)

    root@mylinuxhost:~# pip install snakeviz
    root@mylinuxhost:~# pip3 install snakeviz

    .

  7. Now you can use snakeviz to view the profiling file.

    linuxuser@mylinuxhost:/tmp$ snakeviz multisite.profile


    Screenshot of snakeviz

.Now you can analyze at which point of the request your view needs the most time!

Profiling via cli

  1. The cmk commands have the option to profile them.

    OMD[mysite]:~$ cmk |grep profile
       --profile           Enable profiling mode

    .

  2. The profile file will be created in the current directory. Let's go to tmp and run the cmk command with the profile option.

    ➜  ~ su - at                                        
    OMD[mysite]:~$ cd tmp
    OMD[mysite]:~$ cmk -Afv --profile

    cmk -Afv --profile is only one example. This command will trigger the agent baking via the CLI. You may need to profile a different command.

    .

      1. Now we will see two files:

        OMD[mysite]:~/tmp$ ls |grep profile
        profile.out*
        show_profile.py*

        .

      2. To work with these files, we need to copy them outside the site.

        OMD[mysite]:~/tmp$ cp show_profile.py profile.out /tmp/

        .

      3. Now there are two ways to analyze these files:

        1. Open the profile file via the command line:

          ➜  /tmp ./show_profile.py 
        2. Analyze via snakevize as described here: Checkmk profiling#GUIProfiling

Profile a Checkmk function

Please note that we do not support any changes to our code. If you do this, please keep a backup of the file!


There is an option to profile a function inside Checkmk. This can be either your own code, e.g., a plugin or a checkmk-specific code:

from cmk.utils.profile import profile_call
.....

@profile_call("/tmp/myprofile_dir")
def my_func_to_profile(self):
    print("ding dong")

Analyze a profiling file with python3 but generated on python2

If you're running Checkmk <1.6 and >2.0 on your system, you will also have python2 and python3 installed.

If you generate a profile on Checkmk 1.6 (pyhon2), you won't be able to open this file if python3 is your default python on your system.

There is a simple to achieve this anyway:

The solution is: Python virtualenv inspired by: https://computingforgeeks.com/how-to-install-python2-with-virtualenv-on-ubuntu/

Here is my short step-by-step guide:

# Install virtualenv
sudo apt install virtualenv

# Create a directory for virtualenv
mkdir ~/.virtualenvs

# Change to this directory and create a virtualenv with the python interpreter you want (we will use python2)
cd ~/.virtualenvs
virtualenv --python=python2 env

# Confirm that the right python version is installed
ls env/lib
 
# Activate the new virtualenvironment
source env/bin/activate

# Now you can install all kind of modules inside this python2 context
pip install snakeviz

In this env, you can analyze all profile files generated with python2!

Network Analyze with the Internet browser

  1. Start the Network Monitor
  2. Reload the slow/ crashing view again and save/export this file as .har. Please submit this file to us.

Slow views


This option is only available in Checkmk 2.2 or greater.

Some built-in or own views may take longer time than expected. In order to detect slow views, you have to set:

  • The log level to DEBUG at Setup > General > Global settings > User interface > Log levels > Slow views

  • A threshold (in seconds) at Setup > General > Global settings > User interface > Threshold for slow views

The logging is disabled by default. The default threshold is set to 60 seconds.

Screenshot of slow views threshold set to 60 seconds via global settings


If enabled, one log entry per view rendering that exceeds the configured threshold is logged to var/log/web.log.


A slow-view log entry will look like the following:

2023-10-05 14:01:02,467 [10] [cmk.web.slow-views 783147] View name: logfile, User: cmkadmin, Row limit: None, Limit type: none, URL variables: ['csrf_token=deaacdae-e2ad-47bb-a497-8a41c4f5e378', 
'filled_in=filter', 'is_log_notification_phase=-1', 'limit=none', 'logclass0=on', 'logclass1=on', 'logclass2=on', 'logclass3=on', 'logclass5=on', 'logclass8=on', 'logst_h0=on', 'logst_h1=on', 
'logst_h2=on', 'logst_s0=on', 'logst_s1=on', 'logst_s2=on', 'logst_s3=on', 'logtime_from=400', 'logtime_from_range=86400', 'logtime_until_range=3600', 'view_name=logfile', '_show_filter_form=1'], 
View context: {'optservicegroup': {'optservice_group': '', 'neg_optservice_group': ''}, 'siteopt': {'site': ''}, 'log_class': {'logclass0': 'on', 'logclass1': 'on', 'logclass2': 'on', 'logclass3': 
'on', 'logclass4': '', 'logclass5': 'on', 'logclass6': '', 'logclass8': 'on'}, 'log_notification_phase': {'is_log_notification_phase': '-1'}, 'hostregex': {'host_regex': ''}, 'serviceregex': 
{'service_regex': ''}, 'opthostgroup': {'opthost_group': '', 'neg_opthost_group': ''}, 'logtime': {'logtime_from': '400', 'logtime_until': '', 'logtime_from_range': '86400', 'logtime_until_range': '3600'},
'log_state': {'logst_h0': 'on', 'logst_h1': 'on', 'logst_h2': 'on', 'logst_s0': 'on', 'logst_s1': 'on', 'logst_s2': 'on', 'logst_s3': 'on'}, 'wato_folder': {'wato_folder': ''}}, Unfiltered rows: 
24783, Filtered rows: 24783, Rows after limit: 0, Duration fetching rows: 0.69s, Duration filtering rows: 0.00s, Duration rendering view: 18.44s, Rendering page exceeds 3s: 19.21s