Edgewall Software
Modify

Opened 16 years ago

Closed 15 years ago

Last modified 15 years ago

#6436 closed defect (fixed)

Query links (eg [query: ....]) amazingly slow

Reported by: fabien Owned by: Christian Boos
Priority: highest Milestone: 0.11.2
Component: ticket system Version: 0.10.4
Severity: major Keywords: query
Cc: Branch:
Release Notes:
API Changes:
Internal Changes:

Description (last modified by Christian Boos)

When using multiple [query: ...] in a wiki page, it takes a few seconds and 100% of CPU on the server to generate the page (mod_python + apache2).

Check here : https://lampsvn.epfl.ch/trac/scala/wiki

Other wiki pages are fast. But, if I copy the web to the trac demo site, it works fine and it seems to use the same version as me. My configuration uses sqlite.

Attachments (6)

cache-get_ticket_fields-r6792.diff (1.0 KB ) - added by Christian Boos 16 years ago.
Seems like the Query.from_string is to blame, and the fact that this triggers the creation of a Query object which calls TicketSystem.get_ticket_fields().
cache-get_ticket_fields-r6823.diff (1.7 KB ) - added by Christian Boos 16 years ago.
Same as first patch but with locking add (for latest 0.11dev trunk)
cache-get_ticket_fields-trac-0.10.diff (1.8 KB ) - added by Christian Boos 16 years ago.
Same as first patch but with locking add (this time for 0.10)
cache-get_ticket_fields-trac-0.10.2.diff (1.8 KB ) - added by Christian Boos 16 years ago.
A safer version, with a copy of the fields
cache-get_ticket_fields-r6843.diff (4.9 KB ) - added by Christian Boos 16 years ago.
cache for field data, using locking + cache reset method called when appropriate
t6436-slowness-query-r7610.diff (9.4 KB ) - added by Christian Boos 15 years ago.
Updated patch, doing the restrict_owner transformations outside of the TicketSystem(env).get_ticket_fields()

Download all attachments as: .zip

Change History (36)

comment:2 by Christian Boos, 16 years ago

Description: modified (diff)

comment:3 by Christian Boos, 16 years ago

Milestone: 0.10.50.11.1
Priority: normalhigh

by Christian Boos, 16 years ago

Seems like the Query.from_string is to blame, and the fact that this triggers the creation of a Query object which calls TicketSystem.get_ticket_fields().

comment:4 by fabien, 16 years ago

I just tried to apply the patch on version 0.10.4 First, it looks good, request is not slow anymore, but I get randomly this error : Python Traceback

Traceback (most recent call last):

File "/var/lib/python-support/python2.4/trac/web/main.py", line 406, in dispatch_request

dispatcher.dispatch(req)

File "/var/lib/python-support/python2.4/trac/web/main.py", line 237, in dispatch

resp = chosen_handler.process_request(req)

File "/var/lib/python-support/python2.4/trac/wiki/web_ui.py", line 135, in process_request

self._render_view(req, db, page)

File "/var/lib/python-support/python2.4/trac/wiki/web_ui.py", line 443, in _render_view

req.hdfwiki = {

File "/var/lib/python-support/python2.4/trac/wiki/formatter.py", line 1001, in wiki_to_html

Formatter(env, req, absurls, db).format(wikitext, out, escape_newlines)

File "/var/lib/python-support/python2.4/trac/wiki/formatter.py", line 824, in format

result = re.sub(self.wiki.rules, self.replace, line)

File "sre.py", line 142, in sub

return _compile(pattern, 0).sub(repl, string, count)

File "/var/lib/python-support/python2.4/trac/wiki/formatter.py", line 770, in replace

replacement = self.handle_match(fullmatch)

File "/var/lib/python-support/python2.4/trac/wiki/formatter.py", line 766, in handle_match

return internal_handler(match, fullmatch)

File "/var/lib/python-support/python2.4/trac/wiki/formatter.py", line 364, in _lhref_formatter

return self._make_link(ns, target, match, label)

File "/var/lib/python-support/python2.4/trac/wiki/formatter.py", line 371, in _make_link

escape(label, False))

File "/var/lib/python-support/python2.4/trac/ticket/query.py", line 668, in _format_link

query = Query.from_string(formatter.env, query)

File "/var/lib/python-support/python2.4/trac/ticket/query.py", line 94, in from_string

return cls(env, constraints, kw)

File "/var/lib/python-support/python2.4/trac/ticket/query.py", line 54, in init

if self.order != 'id' \

KeyError: 'name'

Thanks for your help.

comment:5 by Christian Boos, 16 years ago

Thanks for the testing. Well, it seems like I need to be more careful about race conditions here. I'll provide an updated patch shortly.

by Christian Boos, 16 years ago

Same as first patch but with locking add (for latest 0.11dev trunk)

by Christian Boos, 16 years ago

Same as first patch but with locking add (this time for 0.10)

comment:6 by Christian Boos, 16 years ago

Milestone: 0.11.10.11
Status: newassigned

Ok, here's a new patch. Can you please test attachment:cache-get_ticket_fields-trac-0.10.diff (that one applies cleanly on 0.10.4)

comment:7 by fabien, 16 years ago

Ok. I applied it and tried it. It looks good and stable. Thanks a lot !

It's now used in production. I'll let you know if it's still ok under load.

in reply to:  7 comment:8 by Christian Boos, 16 years ago

Replying to fabien:

Ok. I applied it and tried it. It looks good and stable. Thanks a lot !

It's now used in production. I'll let you know if it's still ok under load.

Are you talking about https://lampsvn.epfl.ch/trac/scala/wiki ? If so, are you sure it's with the latest patch attachment:cache-get_ticket_fields-trac-0.10.diff? The exception seem to happen again, and quite systematically for a while. Then, it started to work intermittently. If you're using Apache+mod_python as the web front end, did you do a full restart after patching Trac?

comment:9 by anonymous, 16 years ago

Yes, it's the right URL and I restarted apache2 with the latest patch applied. We also get random errors when creating a new ticket :

Python Traceback

Traceback (most recent call last):

File "/var/lib/python-support/python2.4/trac/web/main.py", line 406, in dispatch_request

dispatcher.dispatch(req)

File "/var/lib/python-support/python2.4/trac/web/main.py", line 237, in dispatch

resp = chosen_handler.process_request(req)

File "/var/lib/python-support/python2.4/trac/ticket/web_ui.py", line 140, in process_request

ticket = Ticket(self.env, db=db)

File "/var/lib/python-support/python2.4/trac/ticket/model.py", line 42, in init

self._init_defaults(db)

File "/var/lib/python-support/python2.4/trac/ticket/model.py", line 62, in _init_defaults

'default_' + fieldname)

KeyError: 'name'

and still on the wiki page :

Python Traceback

Traceback (most recent call last):

File "/var/lib/python-support/python2.4/trac/web/main.py", line 406, in dispatch_request

dispatcher.dispatch(req)

File "/var/lib/python-support/python2.4/trac/web/main.py", line 237, in dispatch

resp = chosen_handler.process_request(req)

File "/var/lib/python-support/python2.4/trac/wiki/web_ui.py", line 135, in process_request

self._render_view(req, db, page)

File "/var/lib/python-support/python2.4/trac/wiki/web_ui.py", line 443, in _render_view

req.hdfwiki = {

File "/var/lib/python-support/python2.4/trac/wiki/formatter.py", line 1001, in wiki_to_html

Formatter(env, req, absurls, db).format(wikitext, out, escape_newlines)

File "/var/lib/python-support/python2.4/trac/wiki/formatter.py", line 824, in format

result = re.sub(self.wiki.rules, self.replace, line)

File "sre.py", line 142, in sub

return _compile(pattern, 0).sub(repl, string, count)

File "/var/lib/python-support/python2.4/trac/wiki/formatter.py", line 770, in replace

replacement = self.handle_match(fullmatch)

File "/var/lib/python-support/python2.4/trac/wiki/formatter.py", line 766, in handle_match

return internal_handler(match, fullmatch)

File "/var/lib/python-support/python2.4/trac/wiki/formatter.py", line 364, in _lhref_formatter

return self._make_link(ns, target, match, label)

File "/var/lib/python-support/python2.4/trac/wiki/formatter.py", line 371, in _make_link

escape(label, False))

File "/var/lib/python-support/python2.4/trac/ticket/query.py", line 668, in _format_link

query = Query.from_string(formatter.env, query)

File "/var/lib/python-support/python2.4/trac/ticket/query.py", line 94, in from_string

return cls(env, constraints, kw)

File "/var/lib/python-support/python2.4/trac/ticket/query.py", line 54, in init

if self.order != 'id' \

KeyError: 'name'

Thanks for your help.

by Christian Boos, 16 years ago

A safer version, with a copy of the fields

comment:10 by Christian Boos, 16 years ago

fabien, sorry for the trouble, but it appears that 0.10 modifies the fields returned by Ticket.get_ticket_fields() (at least deleting the name field, which explains the above error).

I've uploaded another patch (attachment:cache-get_ticket_fields-trac-0.10.2.diff), which appears to work for me on 0.10.4. So far I tested only on trunk, and there it doesn't seem we modify the fields, but it nevertheless seems to be risky now to not copy them, even for trunk.

comment:11 by Christian Boos, 16 years ago

Also, note that with those patches, any changes to the possible values of fields (priority, versions, etc.) won't be taken into account until a server restart. This is a severe limitation. We need to do either something like r6837 or a more sophisticated approach as outlined in TracDev/JournalingProposal earlier today.

by Christian Boos, 16 years ago

cache for field data, using locking + cache reset method called when appropriate

comment:12 by Christian Boos, 16 years ago

The latest patch (attachment:cache-get_ticket_fields-r6843.diff) does the right thing for 0.11.

Unfortunately, the cache invalidation done using config.touch can't be backported to 0.10. For those that will eventually use the attachment:cache-get_ticket_fields-trac-0.10.2.diff patch, you should be aware of this limitation, and know about the need to restart the server after a custom field configuration change or changes to the database concerning the enum fields or the milestones.

comment:13 by fabien, 16 years ago

Thanks for the new patch. I will try it on a test server, but I won't put it now on the real server because of the limitation. I will wait until the release of 0.11

Thanks again.

comment:14 by Christian Boos, 16 years ago

Milestone: 0.110.12
Priority: highhighest

The [ticket] restrict_owner = true setting is problematic here: we'd need to invalidate the cache whenever a user gains or loose TICKET_MODIFY, and there's currently no API for this.

comment:15 by anonymous, 16 years ago

Resolution: fixed
Status: assignedclosed

comment:16 by osimons, 16 years ago

Resolution: fixed
Status: closedreopened

Please don't close tickets that obviously aren't fixed as per cboos' last comment.

in reply to:  14 comment:17 by Christian Boos, 16 years ago

Replying to cboos:

The [ticket] restrict_owner = true setting is problematic here: we'd need to invalidate the cache whenever a user gains or loose TICKET_MODIFY, and there's currently no API for this.

Actually dealing with the restrict_owner logic in Ticket(env).get_ticket_fields() (see ticket/api.py) is wrong, as this completely by-passes the fine-grained permissions. The field options should only be computed one we have the actual ticket id at hand.

Once the above problem gets fixed, the patch introducing cacheing (see comment:12) should be enough to address the speed issue reported in this ticket.

comment:18 by anonymous, 15 years ago

Owner: changed from Christian Boos to anonymous
Status: reopenednew

comment:19 by Remy Blank, 15 years ago

Owner: changed from anonymous to Christian Boos

Please don't change ticket fields without a (good) reason.

comment:20 by Christian Boos, 15 years ago

Milestone: 0.130.11.2

So I'll try to make a fix for 0.11.2 this week-end.

comment:21 by Christian Boos, 15 years ago

Not 100% finished yet, just realized I need to support restrict_owner in the query module as well.

comment:22 by Christian Boos, 15 years ago

#7678 closed as duplicate.

TODO count the number of calls to SELECT username,action FROM permission; (i.e. get_user_permissions), compare before/after the patch.

by Christian Boos, 15 years ago

Updated patch, doing the restrict_owner transformations outside of the TicketSystem(env).get_ticket_fields()

comment:23 by Christian Boos, 15 years ago

Component: wiki systemticket system
Keywords: review added

Please test the attachment:t6436-slowness-query-r7610.diff change, which caches the ticket fields computed by TicketSystem().get_ticket_fields() and invalidates the cache as needed using the config.touch() trick.

The modifications to those fields that used to be done when the restrict_owner flag was enabled should now be done outside of this call, by using the TicketSystem(env).eventually_restrict_owner(field[,ticket]) call.

Rationale:

  • there was no easy way to invalidate the cache when the TICKET_MODIFY permissions changed (comment:14)
  • the cost of this owner restriction feature can be quite huge in itself (comment:22), so only doing this when really needed is helpful
  • that restriction was not taking fine-grained permissions into account (comment:17)

The speed gained by the caching is quite appreciable: on a "pathological" page, the rendering goes down from something like 9s to 0.7s (I had lots of query macros but very few "users", so the savings can only be bigger in real situations).

Also, with this change it should be also much cheaper to create Ticket objects.

comment:24 by Remy Blank, 15 years ago

One quick question: will the config.touch() trick work if trac.ini is not writable by the web server? This is the case in my installations. My guess is that it won't.

in reply to:  24 comment:25 by Christian Boos, 15 years ago

Sorry I replied earlier, but apparently forgot to "Save"…

Replying to rblank:

One quick question: will the config.touch() trick work if trac.ini is not writable by the web server? This is the case in my installations. My guess is that it won't.

No it won't, but as this trick is already used in other places (propagate InterMapTxt updates, install plugin in webadmin), you already have other (minor) issues with this setup.

What is really needed is some kind of cache validation infrastructure, so that when we create caches (we already do in a couple of places), we don't have to resort to new tricks each time but rather check for the validity of the cache, and re-create it if needed. Symmetrically, when we change something that we know will affect a cache, signal the change so that the next check for validity will fail. But I think this is beyond the scope of this ticket, and we could discuss that in #7739 for example.

What we could eventually do is to release 0.11.2 without that change, then apply early in "0.11.3dev", so this will eventually give us more time to get feedback from the field.

comment:26 by Remy Blank, 15 years ago

I have been running some stress-testing for about an hour, using tracd, with very good results. I have a page with 90 [query:...] links, and an environment with about 100 users having TICKET_MODIFY permission. Without patch, the page takes about 25 seconds to load. With the patch, about 2.5 seconds.

Then, I opened 15 tabs with autorefresh every 5 seconds, and watched the pages loading and the debug log. I could see no errors, neither in the browser, nor in the log.

Finally, I ran 8 wget instances fetching the page in a loop. Again, no errors on either client or server side. This gives a good indication that the locking issues above seem to have been solved.

Modifying e.g. a component while the 8 wget instance were fetching did trigger an environment reload, and everything continued working. Memory usage stayed reasonable (I don't remember the exact value, but I think it was around 70 MiB at the end).

in reply to:  26 comment:27 by Christian Boos, 15 years ago

Keywords: review removed
Resolution: fixed
Status: newclosed

Replying to rblank:

(snip) Modifying e.g. a component while the 8 wget instance were fetching did trigger an environment reload, and everything continued working. …

That's quite good, I think this indeed shows the change is robust. Thanks for the testing!

Committed in [7640:7642].

comment:28 by Remy Blank, 15 years ago

BTW, re. [7640], the camelCase variable was my mistake, sorry about that (old habits tend to stick). That code places the "Assign to" field at the end of the form (#7018).

in reply to:  description comment:29 by anonymous, 15 years ago

Type: defecttask

Replying to fabien:

When using multiple [query: ...] in a wiki page, it takes a few seconds and 100% of CPU on the server to generate the page (mod_python + apache2).

Check here : https://lampsvn.epfl.ch/trac/scala/wiki

Other wiki pages are fast. But, if I copy the web to the trac demo site, it works fine and it seems to use the same version as me. My configuration uses sqlite.

comment:30 by Remy Blank, 15 years ago

Type: taskdefect

Modify Ticket

Change Properties
Set your email in Preferences
Action
as closed The owner will remain Christian Boos.
The resolution will be deleted. Next status will be 'reopened'.
to The owner will be changed from Christian Boos to the specified user.

Add Comment


E-mail address and name can be saved in the Preferences .
 
Note: See TracTickets for help on using tickets.