1 .. _PROFILING:

     2 

     3 Profiling and performance

     4 =========================

     5 

     6 If you feel that one of your pages takes more time than it should to be

     7 generated, chances are that you're making too many RQL queries.  Obviously,

     8 there are other reasons but experience tends to show this is the first thing to

     9 track down. Luckily, CubicWeb provides a configuration option to log RQL

    10 queries. In your ``all-in-one.conf`` file, set the **query-log-file** option::

    11 

    12     # web application query log file

    13     query-log-file=/home/user/myapp-rql.log

    14 

    15 Then restart your application, reload your page and stop your application.

    16 The file ``myapp-rql.log`` now contains the list of RQL queries that were

    17 executed during your test. It's a simple text file containing lines such as::

    18 

    19     Any A WHERE X eid %(x)s, X lastname A {'x': 448} -- (0.002 sec, 0.010 CPU sec)

    20     Any A WHERE X eid %(x)s, X firstname A {'x': 447} -- (0.002 sec, 0.000 CPU sec)

    21 

    22 The structure of each line is::

    23 

    24     <RQL QUERY> <QUERY ARGS IF ANY> -- <TIME SPENT>

    25 

    26 CubicWeb also provides the **exlog** command to examine and summarize data found

    27 in such a file:

    28 

    29 .. sourcecode:: sh

    30 

    31     $ cubicweb-ctl exlog /home/user/myapp-rql.log

    32     0.07 50 Any A WHERE X eid %(x)s, X firstname A {}

    33     0.05 50 Any A WHERE X eid %(x)s, X lastname A {}

    34     0.01 1 Any X,AA ORDERBY AA DESC WHERE E eid %(x)s, E employees X, X modification_date AA {}

    35     0.01 1 Any X WHERE X eid %(x)s, X owned_by U, U eid %(u)s {, }

    36     0.01 1 Any B,T,P ORDERBY lower(T) WHERE B is Bookmark,B title T, B path P, B bookmarked_by U, U eid %(x)s {}

    37     0.01 1 Any A,B,C,D WHERE A eid %(x)s,A name B,A creation_date C,A modification_date D {}

    38 

    39 This command sorts and uniquifies queries so that it's easy to see where

    40 is the hot spot that needs optimization.

    41 

    42 Do not neglect to set the **fetch_attrs** attribute you can define in your

    43 entity classes because it can greatly reduce the number of queries executed (see

    44 :ref:`FetchAttrs`).

    45 

    46 You should also know about the **profile** option in the ``all-in-on.conf``. If

    47 set, this option will make your application run in an `hotshot`_ session and

    48 store the results in the specified file.

    49 

    50 .. _hotshot: http://docs.python.org/library/hotshot.html#module-hotshot

    51 

    52 Last but no least, if you're using the PostgreSQL database backend, VACUUMing

    53 your database can significantly improve the performance of the queries (by

    54 updating the statistics used by the query optimizer). Nowadays, this is done

    55 automatically from time to time, but if you've just imported a large amount of

    56 data in your db, you will want to vacuum it (with the analyse option on). Read

    57 the documentation of your database for more information.