Thread

Hello!
I’m testing out the upgrade to EE 1.6 in my development environment. I’m noticing slower response in the Wiki when displaying Recent Changes and am hoping you may have some suggestions as to how to resolve.
Specifically, in my live site which has more wiki entries and revisions than my test site, Recent Changes renders in approx 13 seconds. In test, which is upgraded to wiki 1.1 (EE 1.6), Recent Changes renders in anywhere from 60-78 seconds. I haven’t specifically noticed this occurring on other options in the wiki - only Recent Changes - but am still testing.
No hacks into the wiki code, only changes to the azure wiki template. 
What should I check?
Thank you! -C

P.S. This is on a secured company site so I won’t be able to grant access for others to the site to assist with troubleshooting.

I didn’t think the wiki code had changed up all that much.  What I’d do- first, flip it over to the default theme- see if anything varies that way.

If not- I’d show the template parsing for that template- both on the live and dev server.  See if you spot a difference there.  The EE Wiki seems to be loading the recent changes page speedily- and it’s a pretty big wiki.  I don’t think it’s anything inherent in the upgrade.  Least- I can’t spot why it would be.

(You aren’t pulling in anything from outside sources- feeds, etc- on that page?  That could cause the issue- as it times out on the local version.  But- can’t think why you would be- and switching to the default would be a quick way to check anything like that.)

Hi Robin -
swapped to default theme (unchanged from the install) and same result in test.

re:

You aren’t pulling in anything from outside sources

No - sure not.

Looking at the return from debugging info… I see this:

(0.233559) Calling Class/Method: Wiki/wiki
(0.234488) -> Class Called: Wiki
(58.553069) -> Method Called: wiki
(58.553543) -> Data Returned

Guessing the number in parenthesis is time and this is significantly the biggest stretch between two entries in the debugging info.
On the wiki home page, there’s only a .6 difference between these two.

Hmmm… I can set template parsing on on my live site, but looking at where this delay is, not sure it would show me much other than a quicker response…
Will add some of my own debugging into the recent changes code in mod.wiki.php to see what I can find out and will post back. Suggestions are completely welcomed! 

-C

C, I’m a bit concerned by 13 seconds as well as 60 seconds.  How many entries are in your wiki?  If you look at our wiki, which is fairly substantial, you’ll get an approximate .5 second response on recent changes.

Hi Lisa -
31 articles and 589 revisions, if I’m looking at this right. Not using namespaces.
I’ve included the image of the wiki table info below if that helps. We’re currently saving up to 200 revisions per article in this wiki - but could probably cut that back.

Is there a way I can add in code like the template debug code into the wiki processing? trigger_error doesn’t get me the detailed times I think would be helpful.

-C

I’ll have a look into this.  You’re definitely seeing something that you shouldn’t here. It may be difficult to troubleshoot without any access, though.

C - are you running any third party extensions by any chance?

Hi, C—

Can you turn on SQL Query Output (same place as the template debugger)  and find the queries (two of them) that contain:

FROM exp_wiki_revisions r, exp_members m, exp_wiki_page p

then take those queries and run them in either PHPMyAdmin or in the SQL Manager in EE (Admin -> Utilities) and let me know if they are quick or slow?  They should be very fast.

Thanks!

3 extensions but all my own doing 😛 - none in this area though. (Mine use the following hooks: member_member_register, member_member_login_start, and cp_members_validate_members (all related to setting membership options and our corp single sign on integration).)
Weird thing is that other wiki options are behaving - just those that are based upon recent changes are acting up.
Should I look for anything specific in my template that would affect response?
Should I disable my extensions just to confirm no impact?
I’ll turn on sql debugging as well as run those in the queries and let you know.
-C

If you can take a moment to disable those extensions and try the wiki recent changes page, that would certainly rule that out, so I would recommend it.

Lets find out how those queries go before proceeding, too.  Let me know. =)

SELECT r.*, m.member_id, m.screen_name, m.email, m.url, p.page_namespace, p.page_name AS topic FROM exp_wiki_revisions r, exp_members m, exp_wiki_page p WHERE p.last_updated = r.revision_date AND m.member_id = r.revision_author AND r.page_id = p.page_id AND r.revision_status = 'open' AND r.wiki_id = '3' ORDER BY p.last_updated DESC LIMIT 0, 20;

took less than a second…so I’d say very fast *sigh*

[EDIT: Also—disabling extensions doesn’t seem to have an impact. Same >60 second response… If any if this would impact: running on Win 2003 OS, Apache 2.0.59 http server, php 5.2, mysql 5.]

Hi, C—

First - you are testing this in the default template, correct, and the only thing in the Template screen template is the wiki tag? No other markup or anything?

Same results using default and azure (azure contains my customizations). And yep - here’s the content of my wiki index page:

{exp:wiki base_path="<<mywikiname>>/index" wiki="<<mywikiname>>" theme="azure"}

where <<mywikiname>> is replaced with the actual wiki name…and I’ve tried with azure and default in the theme variable but get same results with either.
Drat!
-C

C (can I call you ‘C’?), you seem like you are comfortable with adding some PHP into your mod.wiki.php for debugging?  If so, you can pepper the recent_changes() function with:

$TMPL->log_item('your log message');

And find out where in the chain the time is coming from.  I’d suggest just using the line numbers for the log messages to help identify which one is which.

Hi Derek -
While I wasn’t sure how to use line number :red: I can translate to line #s and here’s what I get (with items that look suspect in red):

(0.317191) In recent_changes function in mod.wiki.php typography stuff
(0.348937) In recent_changes function in mod.wiki.php new 16 switch stuff
(0.350388) In recent_changes function in mod.wiki.php going into loop for results
(17.630236) In recent_changes function in mod.wiki.php parse switch var stuff
(17.632981) In recent_changes function in mod.wiki.php parse switch var stuff end
(17.913254) In recent_changes function in mod.wiki.php parse switch var stuff
(17.913514) In recent_changes function in mod.wiki.php parse switch var stuff end
(20.910885) In recent_changes function in mod.wiki.php parse switch var stuff
(20.911059) In recent_changes function in mod.wiki.php parse switch var stuff end
(53.908380) In recent_changes function in mod.wiki.php parse switch var stuff
(53.917070) In recent_changes function in mod.wiki.php parse switch var stuff end
(58.399049) In recent_changes function in mod.wiki.php parse switch var stuff
(58.399269) In recent_changes function in mod.wiki.php parse switch var stuff end
(58.631166) In recent_changes function in mod.wiki.php parse switch var stuff
(58.631367) In recent_changes function in mod.wiki.php parse switch var stuff end

new 16 switch stuff is before line 1515
going into loop is line 1518 (after assign_variables & before foreach)
parse switch var stuff immediately precedes line 1581

foreach ($vars['var_single'] as $key => $val)

parse switch var stuff end before   $changes is appended to on line 1609

I’m going to step away for a bit for some lunch and will see if I can drill further down when I get back. Any tips in the meantime as to what I should be looking at (or how exactly to spit out line #) are appreciated.

Thank you!
Carolyn (C is fine too!)