-
Bug
-
Resolution: Fixed
-
High
-
1.6.6
-
None
Users complain about perfromance issues, and looking at the thread dumps, a number of threads are waiting to lock a monitor that is being held by an RSS feed. (see screenshot)
Looking at the debug logs to see how long the requests are taking:
--------------------------------------------------------------- Took 337 2009-05-26 10:20:10,456 DEBUG [btpool0-46] fisheye.perf UpfrontFilter-logRequest - start request /changelog/%7Erss/Repo/rss.xml nosession 2009-05-26 10:20:11,047 DEBUG [btpool0-46] fisheye.app ActionDispatcherServlet-doIt - mapped action changelog to class com.cenqua.fisheye.web.ChangelogServlet pi = /~rss/Repo/rss.xml 2009-05-26 10:20:11,124 DEBUG [btpool0-46] fisheye.app ActionDispatcherServlet-doIt - pi: Repo rss.xml rss 2009-05-26 10:20:11,144 DEBUG [btpool0-46] fisheye.perf RepositoryHandle-acquire - acquire engine on Repo, count=1 2009-05-26 10:20:11,151 DEBUG [btpool0-46] fisheye.perf RepositoryHandle-acquire - acquire engine on Repo, count=2 2009-05-26 10:20:11,156 DEBUG [btpool0-46] fisheye.perf RepositoryHandle-release - release engine on Repo, count=1 2009-05-26 10:20:15,564 DEBUG [btpool0-46] fisheye.perf RecentChangesSearcher-findRecentChangeSets - findRecentChangeSets() on nresults=32 in 0ms + 10ms using And(TermLookup(EntityClass[11] -> EntityClass[120], , null)) + 4349ms + 0ms 2009-05-26 10:25:47,494 DEBUG [btpool0-46] fisheye.perf ChangelogServlet-doRssRequest - changelogViewDir-rss for / in 4941ms then 331381ms for render 2009-05-26 10:25:47,494 DEBUG [btpool0-46] fisheye.perf RepositoryHandle-release - release engine on Repo, count=2 2009-05-26 10:25:47,494 DEBUG [btpool0-46] fisheye.perf UpfrontFilter-logRequest - end request /changelog/%7Erss/Repo/rss.xml sessionid=4fgr66ebnz7f --------------------------------------------------------------- --------------------------------------------------------------- Took 344 2009-05-26 10:20:16,044 DEBUG [btpool0-49] fisheye.perf UpfrontFilter-logRequest - start request /changelog/%7Erss/Repo2/rss.xml nosession 2009-05-26 10:20:16,063 DEBUG [btpool0-49] fisheye.app ActionDispatcherServlet-doIt - mapped action changelog to class com.cenqua.fisheye.web.ChangelogServlet pi = /~rss/Repo2/rss.xml 2009-05-26 10:20:16,063 DEBUG [btpool0-49] fisheye.app ActionDispatcherServlet-doIt - pi: Repo2 rss.xml rss 2009-05-26 10:20:16,063 DEBUG [btpool0-49] fisheye.perf RepositoryHandle-acquire - acquire engine on Repo2, count=1 2009-05-26 10:20:16,085 DEBUG [btpool0-49] fisheye.perf RepositoryHandle-acquire - acquire engine on Repo2, count=2 2009-05-26 10:20:16,104 DEBUG [btpool0-49] fisheye.perf RepositoryHandle-release - release engine on Repo2, count=1 2009-05-26 10:20:21,003 DEBUG [btpool0-49] fisheye.perf RecentChangesSearcher-findRecentChangeSets - findRecentChangeSets() on nresults=18 in 0ms + 8ms using And(TermLookup(EntityClass[11] -> EntityClass[120], , null)) + 4869ms + 0ms 2009-05-26 10:26:00,534 DEBUG [btpool0-49] fisheye.perf ChangelogServlet-doRssRequest - changelogViewDir-rss for / in 5469ms then 338951ms for render 2009-05-26 10:26:00,727 DEBUG [btpool0-49] fisheye.perf RepositoryHandle-release - release engine on Repo2, count=2 2009-05-26 10:26:00,977 DEBUG [btpool0-49] fisheye.perf UpfrontFilter-logRequest - end request /changelog/%7Erss/Repo2/rss.xml sessionid=mt7l8dixvqd4 --------------------------------------------------------------- --------------------------------------------------------------- Took 86 2009-05-26 10:24:53,793 DEBUG [btpool0-52] fisheye.perf UpfrontFilter-logRequest - start request /changelog/%7Erss/Repo2/rss.xml nosession 2009-05-26 10:24:57,062 DEBUG [btpool0-52] fisheye.app ActionDispatcherServlet-doIt - mapped action changelog to class com.cenqua.fisheye.web.ChangelogServlet pi = /~rss/Repo2/rss.xml 2009-05-26 10:24:57,556 DEBUG [btpool0-52] fisheye.app ActionDispatcherServlet-doIt - pi: Repo2 rss.xml rss 2009-05-26 10:24:57,754 DEBUG [btpool0-52] fisheye.perf RepositoryHandle-acquire - acquire engine on Repo2, count=3 2009-05-26 10:24:58,714 DEBUG [btpool0-52] fisheye.perf RepositoryHandle-acquire - acquire engine on Repo2, count=4 2009-05-26 10:24:58,850 DEBUG [btpool0-52] fisheye.perf RepositoryHandle-release - release engine on Repo2, count=3 2009-05-26 10:25:21,826 DEBUG [btpool0-52] fisheye.perf RecentChangesSearcher-findRecentChangeSets - findRecentChangeSets() on nresults=18 in 0ms + 166ms using And(TermLookup(EntityClass[11] -> EntityClass[120], , null)) + 22330ms + 0ms 2009-05-26 10:26:19,246 DEBUG [btpool0-52] fisheye.perf ChangelogServlet-doRssRequest - changelogViewDir-rss for / in 23410ms then 56860ms for render 2009-05-26 10:26:19,336 DEBUG [btpool0-52] fisheye.perf RepositoryHandle-release - release engine on Repo2, count=1 2009-05-26 10:26:19,336 DEBUG [btpool0-52] fisheye.perf UpfrontFilter-logRequest - end request /changelog/%7Erss/Repo2/rss.xml sessionid=12by5bnrl5mr0 --------------------------------------------------------------- --------------------------------------------------------------- Took 90 2009-05-26 10:24:53,813 DEBUG [btpool0-54] fisheye.perf UpfrontFilter-logRequest - start request /changelog/%7Erss/Repo/rss.xml nosession 2009-05-26 10:24:57,047 DEBUG [btpool0-54] fisheye.app ActionDispatcherServlet-doIt - mapped action changelog to class com.cenqua.fisheye.web.ChangelogServlet pi = /~rss/Repo/rss.xml 2009-05-26 10:24:57,706 DEBUG [btpool0-54] fisheye.app ActionDispatcherServlet-doIt - pi: Repo rss.xml rss 2009-05-26 10:24:58,175 DEBUG [btpool0-54] fisheye.perf RepositoryHandle-acquire - acquire engine on Repo, count=3 2009-05-26 10:24:58,858 DEBUG [btpool0-54] fisheye.perf RepositoryHandle-acquire - acquire engine on Repo, count=4 2009-05-26 10:24:58,918 DEBUG [btpool0-54] fisheye.perf RepositoryHandle-release - release engine on Repo, count=3 2009-05-26 10:25:32,307 DEBUG [btpool0-54] fisheye.perf RecentChangesSearcher-findRecentChangeSets - findRecentChangeSets() on nresults=32 in 1ms + 3ms using And(TermLookup(EntityClass[11] -> EntityClass[120], , null)) + 31443ms + 0ms 2009-05-26 10:26:23,644 DEBUG [btpool0-54] fisheye.perf ChangelogServlet-doRssRequest - changelogViewDir-rss for / in 35443ms then 49068ms for render 2009-05-26 10:26:23,644 DEBUG [btpool0-54] fisheye.perf RepositoryHandle-release - release engine on Repo, count=1 2009-05-26 10:26:23,645 DEBUG [btpool0-54] fisheye.perf UpfrontFilter-logRequest - end request /changelog/%7Erss/Repo/rss.xml sessionid=1rjekj3kwflsn --------------------------------------------------------------- --------------------------------------------------------------- Took 62 2009-05-26 10:25:29,997 DEBUG [btpool0-61] fisheye.perf UpfrontFilter-logRequest - start request /changelog/%7Erss/Repo/rss.xml nosession 2009-05-26 10:25:30,445 DEBUG [btpool0-61] fisheye.app ActionDispatcherServlet-doIt - mapped action changelog to class com.cenqua.fisheye.web.ChangelogServlet pi = /~rss/Repo/rss.xml 2009-05-26 10:25:30,445 DEBUG [btpool0-61] fisheye.app ActionDispatcherServlet-doIt - pi: Repo rss.xml rss 2009-05-26 10:25:30,455 DEBUG [btpool0-61] fisheye.perf RepositoryHandle-acquire - acquire engine on Repo, count=3 2009-05-26 10:25:30,493 DEBUG [btpool0-61] fisheye.perf RepositoryHandle-acquire - acquire engine on Repo, count=4 2009-05-26 10:25:30,514 DEBUG [btpool0-61] fisheye.perf RepositoryHandle-release - release engine on Repo, count=3 2009-05-26 10:25:55,756 DEBUG [btpool0-61] fisheye.perf RecentChangesSearcher-findRecentChangeSets - findRecentChangeSets() on nresults=32 in 0ms + 47ms using And(TermLookup(EntityClass[11] -> EntityClass[120], , null)) + 24199ms + 0ms 2009-05-26 10:26:31,767 DEBUG [btpool0-61] fisheye.perf ChangelogServlet-doRssRequest - changelogViewDir-rss for / in 27360ms then 33642ms for render 2009-05-26 10:26:31,843 DEBUG [btpool0-61] fisheye.perf RepositoryHandle-release - release engine on Repo, count=0 2009-05-26 10:26:31,854 DEBUG [btpool0-61] fisheye.perf UpfrontFilter-logRequest - end request /changelog/%7Erss/Repo/rss.xml sessionid=ypxdu63hx4sl --------------------------------------------------------------- --------------------------------------------------------------- Took 60 2009-05-26 10:25:36,859 DEBUG [btpool0-60] fisheye.perf UpfrontFilter-logRequest - start request /changelog/%7Erss/Repo2/rss.xml nosession 2009-05-26 10:25:36,993 DEBUG [btpool0-60] fisheye.app ActionDispatcherServlet-doIt - mapped action changelog to class com.cenqua.fisheye.web.ChangelogServlet pi = /~rss/Repo2/rss.xml 2009-05-26 10:25:37,005 DEBUG [btpool0-60] fisheye.app ActionDispatcherServlet-doIt - pi: Repo2 rss.xml rss 2009-05-26 10:25:37,033 DEBUG [btpool0-60] fisheye.perf RepositoryHandle-acquire - acquire engine on Repo2, count=3 2009-05-26 10:25:37,054 DEBUG [btpool0-60] fisheye.perf RepositoryHandle-acquire - acquire engine on Repo2, count=4 2009-05-26 10:25:37,125 DEBUG [btpool0-60] fisheye.perf RepositoryHandle-release - release engine on Repo2, count=3 2009-05-26 10:25:49,124 DEBUG [btpool0-60] fisheye.perf RecentChangesSearcher-findRecentChangeSets - findRecentChangeSets() on nresults=18 in 0ms + 0ms using And(TermLookup(EntityClass[11] -> EntityClass[120], , null)) + 11638ms + 0ms 2009-05-26 10:26:36,721 DEBUG [btpool0-60] fisheye.perf ChangelogServlet-doRssRequest - changelogViewDir-rss for / in 12922ms then 46663ms for render 2009-05-26 10:26:36,721 DEBUG [btpool0-60] fisheye.perf RepositoryHandle-release - release engine on Repo2, count=0 2009-05-26 10:26:36,722 DEBUG [btpool0-60] fisheye.perf UpfrontFilter-logRequest - end request /changelog/%7Erss/Repo2/rss.xml sessionid=9u4g44myqxjo --------------------------------------------------------------- --------------------------------------------------------------- Took 114 2009-05-26 10:24:54,827 DEBUG [btpool0-58] fisheye.perf UpfrontFilter-logRequest - start request /changelog/%7Erss/Repo3/trunk/rss.xml sessionid=189c1nn953x5p 2009-05-26 10:25:00,830 DEBUG [btpool0-58] fisheye.app ActionDispatcherServlet-doIt - mapped action changelog to class com.cenqua.fisheye.web.ChangelogServlet pi = /~rss/Repo3/trunk/rss.xml 2009-05-26 10:25:00,926 DEBUG [btpool0-58] fisheye.app ActionDispatcherServlet-doIt - pi: Repo3 trunk/rss.xml rss 2009-05-26 10:25:00,935 DEBUG [btpool0-58] fisheye.perf RepositoryHandle-acquire - acquire engine on Repo3, count=2 2009-05-26 10:25:00,967 DEBUG [btpool0-58] fisheye.perf RepositoryHandle-acquire - acquire engine on Repo3, count=3 2009-05-26 10:25:01,146 DEBUG [btpool0-58] fisheye.perf RepositoryHandle-release - release engine on Repo3, count=2 2009-05-26 10:25:50,376 DEBUG [btpool0-58] fisheye.perf RecentChangesSearcher-findRecentChangeSets - findRecentChangeSets() on trunk nresults=18 in 2ms + 737ms using And(TermLookup(EntityClass[11] -> EntityClass[120], trunk, null)) + 45193ms + 0ms 2009-05-26 10:26:48,217 DEBUG [btpool0-58] fisheye.perf ChangelogServlet-doRssRequest - changelogViewDir-rss for /trunk in 67468ms then 39202ms for render 2009-05-26 10:26:48,243 DEBUG [btpool0-58] fisheye.perf RepositoryHandle-release - release engine on Repo3, count=0 2009-05-26 10:26:48,243 DEBUG [btpool0-58] fisheye.perf UpfrontFilter-logRequest - end request /changelog/%7Erss/Repo3/trunk/rss.xml sessionid=189c1nn953x5p ---------------------------------------------------------------
We see that findRecentChangeSets and rendering is taking a long time. findRecentChangeSets is most likely the suspect for holding onto the lock on the inifinitydb.
We need to investigate and reduce the time taken for these requests.
- is related to
-
FE-1628 Allow an option to disable RSS feeds like you can disable watches
- Closed