On Sun, Feb 8, 2009 at 1:32 PM, Christian Boos <[email protected]> wrote: >> >> Any ideas why Trac may stop syncing cache with repository after >> upgrading to 0.11.2.1? >> The log is full of strange messages about insufficient privileges for >> creating pages. >> >> 2009-02-07 17:55:11,224 Trac[__init__] DEBUG: Dispatching <Request >> "GET u'/timeline'"> >> 2009-02-07 17:55:11,402 Trac[__init__] DEBUG: Subversion bindings imported >> 2009-02-07 17:55:11,417 Trac[__init__] INFO: repos rev [2557] != >> cached rev [2414] >> > > I've already seen that once on someone's machine (hi John ;-) ), without > having a clue about it. > So it would be very helpful if you could spend some time debugging this > in depth. > By inserting enough debug statements in trac/versioncontrol/cache.py, > you should be able to get a clue about what's going on (e.g. missing > read permission on the svn repo?).
It turned out to be locked cache after timeout. At first I thought about a race condition, but it was false. The cache can easily be jammed with a long resync from repository on a busy server. It took about 40 seconds to sync 200 revisions before timeout occurred. Take a cache.py sync() http://trac.edgewall.org/browser/branches/0.11-stable/trac/versioncontrol/cache.py#L158 On line 159 we check if a revision is being entered in DB by looking if next revision number is already present in `revisions` table. That means another thread is made an INSERT in line 184. The cache is now locked. To unlock it, another thread should update youngest revision at line 221. So, the problem is when a timeout occurs during execution of 202:221 - there is an update in `node_change` table that can potentially take a long time to experience a timeout (esp. when server is under a heavy load). There are also cset.get_changes() and self.repos.next_rev(next_youngest) calls that can contribute to the issue. I haven't found other way to recover than to manually patch DB. DELETE FROM `node_change` WHERE `rev` > 2260; DELETE FROM `revision` WHERE `rev` > 2260; UPDATE `system` SET `value` = 2260 WHERE `name` = 'youngest_rev' LIMIT 1; Seems like the only way to avoid locking is to introduce timeout on 184:221 cache operations. Like additional `sync_time_started` = None or something else as an explicit flag. >> 2009-02-07 17:55:11,424 Trac[__init__] DEBUG: Retrieving session for >> ID '4b0a7707907d96a01f8ff7e0' >> 2009-02-07 17:55:11,803 Trac[__init__] DEBUG: Prepare chrome data for request >> 2009-02-07 17:55:11,805 Trac[__init__] DEBUG: No policy allowed >> anonymous performing TRAC_ADMIN on None >> 2009-02-07 17:55:11,806 Trac[__init__] DEBUG: No policy allowed >> anonymous performing PERMISSION_GRANT on None >> 2009-02-07 17:55:11,806 Trac[__init__] DEBUG: No policy allowed >> anonymous performing PERMISSION_REVOKE on None >> 2009-02-07 17:55:11,336 Trac[__init__] DEBUG: No policy allowed >> anonymous performing EMAIL_VIEW on None >> 2009-02-07 17:55:12,509 Trac[__init__] DEBUG: Updating wiki page index >> 2009-02-07 17:55:12,511 Trac[__init__] DEBUG: No policy allowed >> anonymous performing WIKI_CREATE on <Resource u'wiki:FreeFindData'> >> 2009-02-07 17:55:12,013 Trac[__init__] DEBUG: No policy allowed >> anonymous performing WIKI_CREATE on <Resource u'wiki:KeyBarLabels'> >> 2009-02-07 17:55:12,746 Trac[__init__] DEBUG: No policy allowed >> anonymous performing WIKI_CREATE on <Resource u'wiki:GoToFile'> >> 2009-02-07 17:55:12,266 Trac[__init__] DEBUG: No policy allowed >> anonymous performing WIKI_CREATE on <Resource u'wiki:GlobalLock'> >> 2009-02-07 17:55:12,308 Trac[__init__] DEBUG: No policy allowed >> <...> > > That's puzzling as well. Do you have some random page generation plugin > installed? :-) > It might be a bot trying to visit links to non-existing Wiki pages, try > to set `[wiki] ignore_missing_pages = true` in your trac.ini file... I thought about a bot too, because page names are different every time. These must be references from Source Browser, because Timeline references contain <a> tags without href attributes. Perhaps these were added from another thread while I was debugging my Timeline view. It would be more useful to see pid or thread id displayed in log instead of Trac[__init__] string. Does this Trac[__init__] change at all? -- --anatoly t. --~--~---------~--~----~------------~-------~--~----~ You received this message because you are subscribed to the Google Groups "Trac Development" group. To post to this group, send email to [email protected] To unsubscribe from this group, send email to [email protected] For more options, visit this group at http://groups.google.com/group/trac-dev?hl=en -~----------~----~----~----~------~----~------~--~---
