Custom Query / Reports are very slow

[michaelni@…]

Simply listing issues is very slow, the more issues are listed and the more columns are, the slower. That is 10-20 seconds for displaying 300 tickets with all columns. While the comma delimited output of the same query just takes a fraction of a second. Speed also does not seem to improve by repeating the request.

The problem (to a lesser extent) can be reproduced with trac.edgewall.org too. I suspect its the same issue as the symptoms look the same. But iam just guessing here

here's an example:

time wget '​http://trac.edgewall.org/query?max=1000&col=id&col=summary&col=status&col=owner&col=type&col=priority&col=milestone&col=component&col=version&col=severity&col=resolution&col=time&col=reporter&col=keywords&col=cc&order=priority' —2012-03-21 00:37:14— ​http://trac.edgewall.org/query?max=1000&col=id&col=summary&col=status&col=owner&col=type&col=priority&col=milestone&col=component&col=version&col=severity&col=resolution&col=time&col=reporter&col=keywords&col=cc&order=priority Resolving trac.edgewall.org… 176.9.102.26 Connecting to trac.edgewall.org|176.9.102.26|:80… connected. HTTP request sent, awaiting response… 200 Ok Length: 1762922 (1.7M) [text/html] Saving to: “query?max=1000&col=id&col=summary&col=status&col=owner&col=type&col=priority&col=milestone&col=component&col=version&col=severity&col=resolution&col=time&col=reporter&col=keywords&col=cc&order=priority”

2012-03-21 00:37:24 (1.05 MB/s) - “query?max=1000&col=id&col=summary&col=status&col=owner&col=type&col=priority&col=milestone&col=component&col=version&col=severity&col=resolution&col=time&col=reporter&col=keywords&col=cc&order=priority” saved [1762922/1762922]

real 0m9.574s user 0m0.008s sys 0m0.068s

time wget '​http://trac.edgewall.org/query?format=csv&max=1000&col=id&col=summary&col=status&col=owner&col=type&col=priority&col=milestone&col=component&col=version&col=severity&col=resolution&col=time&col=reporter&col=keywords&col=cc&order=priority' —2012-03-21 00:38:54— ​http://trac.edgewall.org/query?format=csv&max=1000&col=id&col=summary&col=status&col=owner&col=type&col=priority&col=milestone&col=component&col=version&col=severity&col=resolution&col=time&col=reporter&col=keywords&col=cc&order=priority Resolving trac.edgewall.org… 176.9.102.26 Connecting to trac.edgewall.org|176.9.102.26|:80… connected. HTTP request sent, awaiting response… 200 Ok Length: 164781 (161K) [text/csv] Saving to: “query?format=csv&max=1000&col=id&col=summary&col=status&col=owner&col=type&col=priority&col=milestone&col=component&col=version&col=severity&col=resolution&col=time&col=reporter&col=keywords&col=cc&order=priority.1”

2012-03-21 00:38:55 (671 KB/s) - “query?format=csv&max=1000&col=id&col=summary&col=status&col=owner&col=type&col=priority&col=milestone&col=component&col=version&col=severity&col=resolution&col=time&col=reporter&col=keywords&col=cc&order=priority.1” saved [164781/164781]

real 0m0.691s user 0m0.000s sys 0m0.012s

[Christian Boos]

>>> size_html, time_html = 1762922.0, 9.574
>>> size_text, time_text = 164781.0, 0.691
>>> size_html / size_text, time_html / time_text
(10.698575685303524, 13.855282199710565)

Pretty much the same ratio, and the remaining difference can certainly be explained by the extra complexity of Genshi' html templates vs. text templates.

Of course, one wouldn't expect that the major part of the processing time for such queries is devoted to the rendering, but that's a well known issue we have with our beloved Genshi templating engine ;-)

In the meantime, you should try to use a recent version of Genshi (at least 0.6; as you didn't say which Trac version you were using, you might be using a Genshi 0.5 version).

See also TracDev/Performance#Genshi.