Special:ActiveUsers query is very slow
Closed, ResolvedPublic

Description

On profiling it is taking 123s on average, on my test it took over 40s on translatewiki.net.

Truncated query:
query: SELECT rc_user_text AS user_name,rc_user_text,user_id,COUNT(*) AS recentedits,MAX(ipb_deleted) AS ipb_deleted FROM bw_recentchanges FORCE INDEX (rc_user_text) INNER JOIN bw_user ON ((rc_user_text=user_name)) LEFT JOIN bw_ipblocks ON ((user_id


Version: 1.21.x
Severity: normal
See Also:
https://bugzilla.wikimedia.org/show_bug.cgi?id=59988
https://bugzilla.wikimedia.org/show_bug.cgi?id=60468

bzimport set Reference to bz41078.
Nikerabbit created this task.Via LegacyOct 16 2012, 11:27 AM
Reedy added a comment.Via ConduitOct 17 2012, 6:28 PM

Need to grab a full SQL query and run EXPLAIN on it....

Reedy added a comment.Via ConduitOct 17 2012, 6:30 PM

Query wikidb (23) (slave):

SELECT /* IndexPager::buildQueryInfo (ActiveUsersPager) Reedy */ rc_user_text AS user_name,rc_user_text,user_id,COUNT(*) AS recentedits,MAX(ipb_deleted) AS ipb_deleted FROM mw_recentchanges FORCE INDEX (rc_user_text) INNER JOIN mw_user ON ((rc_user_text=user_name)) LEFT JOIN mw_ipblocks ON ((user_id=ipb_user) AND ipb_auto = '0') WHERE (rc_user > 0) AND (ipb_deleted IS NULL OR ipb_deleted = 0) AND (rc_log_type IS NULL OR rc_log_type != 'newusers') AND (rc_timestamp > '20120917182934')

Reedy added a comment.Via ConduitOct 17 2012, 6:31 PM

mysql> explain SELECT /* IndexPager::buildQueryInfo (ActiveUsersPager) Reedy */ rc_user_text AS user_name,rc_user_text,user_id,COUNT(*) AS recentedits,MAX(ipb_deleted) AS ipb_deleted FROM recentchanges FORCE INDEX (rc_user_text) INNER JOIN user ON ((rc_user_text=user_name)) LEFT JOIN ipblocks ON ((user_id=ipb_user) AND ipb_auto = '0') WHERE (rc_user > 0) AND (ipb_deleted IS NULL OR ipb_deleted = 0) AND (rc_log_type IS NULL OR rc_log_type != 'newusers') AND (rc_timestamp > '20120917182934');
+----+-------------+---------------+--------+---------------+-----------+---------+------------------------------------------+-------+-------------+

idselect_typetabletypepossible_keyskeykey_lenrefrowsExtra

+----+-------------+---------------+--------+---------------+-----------+---------+------------------------------------------+-------+-------------+

1SIMPLErecentchangesALLrc_user_textNULLNULLNULL11096Using where
1SIMPLEusereq_refuser_nameuser_name257mediawikiwiki.recentchanges.rc_user_text1Using index
1SIMPLEipblocksrefipb_useripb_user4mediawikiwiki.user.user_id1Using where

+----+-------------+---------------+--------+---------------+-----------+---------+------------------------------------------+-------+-------------+
3 rows in set (0.01 sec)

Nikerabbit added a comment.Via ConduitOct 17 2012, 9:33 PM

I guess the problem is recentchanges table which is not using index. It's scanning millions of row in translatewiki.net

Nikerabbit added a comment.Via ConduitOct 17 2012, 10:34 PM

Makes only marginal difference:

101 rows in set (35.61 sec)

mysql> explain SELECT /* IndexPager::buildQueryInfo (ActiveUsersPager) Nike */ rc_user_text AS user_name,rc_user_text,user_id,COUNT(*) AS recentedits,MAX(ipb_user) AS blocked FROM bw_recentchanges FORCE INDEX (rc_user_text) INNER JOIN bw_user ON ((rc_user_text=user_name)) LEFT JOIN bw_ipblocks ON ((user_id=ipb_user) AND ipb_auto = '0' AND ipb_deleted = '1') WHERE (rc_user > 0) AND (ipb_deleted IS NULL) AND (rc_log_type IS NULL OR rc_log_type != 'newusers') AND (rc_timestamp >= '20120917223021') GROUP BY rc_user_text,user_id ORDER BY rc_user_text LIMIT 101;
+----+-------------+------------------+--------+---------------+--------------+---------+-----------------------------------------+--------+-------------------------+

idselect_typetabletypepossible_keyskeykey_lenrefrowsExtra

+----+-------------+------------------+--------+---------------+--------------+---------+-----------------------------------------+--------+-------------------------+

1SIMPLEbw_recentchangesindexrc_user_textrc_user_text273NULL155136Using where
1SIMPLEbw_usereq_refuser_nameuser_name257mediawiki.bw_recentchanges.rc_user_text1Using index
1SIMPLEbw_ipblocksrefipb_useripb_user4mediawiki.bw_user.user_id1Using where; Not exists

+----+-------------+------------------+--------+---------------+--------------+---------+-----------------------------------------+--------+-------------------------+
3 rows in set (0.01 sec)

Umherirrender added a comment.Via ConduitOct 19 2012, 4:37 PM

That pages was slow on translatewiki before my changes, because translatewiki has set RCMaxAge to a high value and that result in many rows in the recentchange table.

It is hard to say, which query will give the best result for this.

Reedy added a comment.Via ConduitOct 19 2012, 5:19 PM

(In reply to comment #9)

That pages was slow on translatewiki before my changes, because translatewiki
has set RCMaxAge to a high value and that result in many rows in the
recentchange table.

It is hard to say, which query will give the best result for this.

It just seemed a likely candidate as it had been deployed, then it was noticed it was slow. Granted, it's not that commit.

Reverted https://gerrit.wikimedia.org/r/#/c/28689/

Aklapper added a comment.Via ConduitJan 15 2013, 4:07 PM

Can this problem still be seen?

Reedy added a comment.Via ConduitJan 15 2013, 4:18 PM

http://translatewiki.net/wiki/Special:ActiveUsers

It's certainly not fast...

<!-- Served in 12.943 secs. -->

Less than half a second on enwiki

Umherirrender added a comment.Via ConduitMar 15 2013, 1:44 PM

query reduced with gerrit 51290

Nemo_bis added a comment.Via ConduitMar 15 2013, 2:36 PM

(In reply to comment #12)

<!-- Served in 12.943 secs. -->

(In reply to comment #13)

query reduced with Gerrit change #51290

-rakkaus:#mediawiki-i18n- [nike] updated translatewiki.net to 7ca8090 2013-03-15 14:32:34 +0000 (45 seconds ago)

Now:
<!-- Served in 7.325 secs. -->
<!-- Served in 6.851 secs. -->

duplicatebug added a comment.Via ConduitMar 26 2013, 8:08 PM

special page was removed with gerrit 55807

Ankry added a comment.Via ConduitApr 5 2013, 10:46 PM

Please revert this change.

This page is (was?) very useful on many small and even medium wikis with relatively low number of edits and it was not a performance hit there.
The summarized, up-to-date information about active users or even a list of active users is very useful.
If there is a performance problem on some wikis (translatewiki?) it should be solved in a per-wiki way. I see at least three ways:

  1. limit time period or number of analyzed edits
  1. use some caching/locking to avoid this call be called too often
  1. disable it in per-wiki way only on wikis where a problem occurs

Or, at least, offer an alternative while removing this page.

matmarex added a comment.Via ConduitApr 5 2013, 10:56 PM

(CC-ing code submitter and reviewers.)

aaron added a comment.Via ConduitApr 5 2013, 11:03 PM

One thing that slowed it down was showing the count of the recent edits (an expensive GROUP BY). It could have used a LIMIT 10 subquery for each or just not have that count at all and maybe just use user_editcount (total edits, recent or not).

matmarex added a comment.Via ConduitApr 6 2013, 7:35 PM
  • Bug 46938 has been marked as a duplicate of this bug. ***
Hutchy68 added a comment.Via ConduitApr 7 2013, 1:47 AM

(In reply to comment #16)

Please revert this change.

This page is (was?) very useful on many small and even medium wikis with
relatively low number of edits and it was not a performance hit there.
The summarized, up-to-date information about active users or even a list of
active users is very useful.
If there is a performance problem on some wikis (translatewiki?) it should be
solved in a per-wiki way. I see at least three ways:

  1. limit time period or number of analyzed edits
  2. use some caching/locking to avoid this call be called too often
  3. disable it in per-wiki way only on wikis where a problem occurs

    Or, at least, offer an alternative while removing this page.

+1 on this revert.

I'm sorry, but it was a 'axe it' mentality based load on wikipedia because of its unique - large data set. If the query is trash, tweak or improve it. Pull it from somewhere else. Too many smaller wikis rely on what is already a small set of metric data for Mediawiki. Rate limit it, cache it or allow for disabling with a boolean switch.

MZMcBride added a comment.Via ConduitApr 7 2013, 5:36 PM

If the addition of this feature was "poorly thought out," surely its removal had even less consideration. Looking at https://gerrit.wikimedia.org/r/55807, was this feature really removed in just 20 minutes? Won't this be a breaking change in the MediaWiki API (among the other ripple effects)?

(In reply to comment #12)

http://translatewiki.net/wiki/Special:ActiveUsers

It's certainly not fast...

<!-- Served in 12.943 secs. -->

So on the wiki that set its "recent changes" to be _years_, it's slightly slow. On a giant production database, however...

Less than half a second on enwiki

This really justified removing the feature in the course of an hour? I'm a bit baffled here.

Nikerabbit added a comment.Via ConduitApr 7 2013, 5:47 PM

It was slow on WMF too:

[23:45:38] binasher> ^demon: i noticed that one of the enwiki slaves was lagging a bunch and getting a bunch of ActiveUsersPager queries.. looks like an uncommonly called page, but the query results in just about a full scan of recentchanges with an on disk temp table
[23:46:03] binasher> takes around 2 minutes on a busy server if all pages are in the bufferpool
[23:46:08] binasher> and 8 if not

bzimport added a comment.Via ConduitApr 11 2013, 12:26 PM

ravidreams_03 wrote:

Hi,

We have been using this metric in Tamil Wikipedia to identify and encourage new and active users. Can we get this feature back, please? At least, you can switch this on and off per wiki or provide an option to run this through extensions.

Thanks.

bzimport added a comment.Via ConduitApr 12 2013, 2:50 PM

grazeroleg wrote:

+1 to Ravishankar. In Lezgi Wikipedia we have the rules of administrators election - voter must have at least 10 edits in the «Articles», «Templates» and/or «Category» namespaces within the last 30 days.

Rillke added a comment.Via ConduitApr 13 2013, 10:48 AM

I wonder, why I didn't read it in the wikitech-ambassadors mailing list. Perhaps this change was just not submitted to that mailing list?

MZMcBride added a comment.Via ConduitApr 18 2013, 4:03 AM

(In reply to comment #25)

I wonder, why I didn't read it in the wikitech-ambassadors mailing list.
Perhaps this change was just not submitted to that mailing list?

Related: bug 47350 ("Restore Special:ActiveUsers prior to the release of MediaWiki 1.21")

Bawolff added a comment.Via ConduitApr 21 2013, 2:41 PM

If the query really is that slow, could be re-done as a cached special page perhaps.

Bawolff added a comment.Via ConduitApr 23 2013, 5:20 PM
  • Bug 47559 has been marked as a duplicate of this bug. ***
duplicatebug added a comment.Via ConduitMay 10 2013, 3:55 PM

(In reply to comment #15)

special page was removed with Gerrit change #55807

Back with gerrit 58686

gerrit 62408 refactored the query. Please test if this helps with the performance. Thanks.

Nikerabbit added a comment.Via ConduitMay 11 2013, 7:03 AM

Serves in about one second on translatewiki.net now. Should we close this bug now?

Nemo_bis added a comment.Via ConduitMay 11 2013, 8:55 AM

(In reply to comment #30)

Serves in about one second on translatewiki.net now. Should we close this bug
now?

Probably. On the other hand, it should be restored on en.wiki with 1.22wmf4 on Monday, May 20, 2013, so we could as well wait a week and see.

bzimport added a comment.Via ConduitMay 11 2013, 10:23 AM

grazeroleg wrote:

Restore Active Users in small Wikipedias! The decision to remove it was harmful for small Wikis!

Nemo_bis added a comment.Via ConduitMay 11 2013, 10:29 AM

(In reply to comment #32)

Restore Active Users in small Wikipedias! The decision to remove it was
harmful
for small Wikis!

As I said, it's going to be restored on all wikis (and then disabled again on some wikis if needed). See the calendar for 1.22wmf4 code update: https://www.mediawiki.org/wiki/MediaWiki_1.22/Roadmap

Umherirrender added a comment.Via ConduitMay 23 2013, 5:41 PM

All wikis now on 1.22wmf4, it is still active on enwiki, looks like the new query is not slow anymore -> FIXED

aaron added a comment.Via ConduitMay 23 2013, 5:52 PM

(In reply to comment #34)

All wikis now on 1.22wmf4, it is still active on enwiki, looks like the new
query is not slow anymore -> FIXED

It's still sometimes slow for enwiki/wikidatawiki, not sure exactly why though.

Nemo_bis added a comment.Via ConduitMay 23 2013, 6:00 PM

For the records, on en.wiki it's now like this:

Served by mw1022 in 0.453 secs.
Served by mw1077 in 0.343 secs.
Served by mw1043 in 0.467 secs.

MZMcBride added a comment.Via ConduitMay 24 2013, 3:17 AM

Query cache and other caching layers likely affect any attempts at benchmarking.

gerritbot added a comment.Via ConduitFeb 2 2014, 5:35 PM

Change 110299 had a related patch set uploaded by Nemo bis:
Made ActiveUsers use querycache and do staggered updates on view

https://gerrit.wikimedia.org/r/110299

gerritbot added a comment.Via ConduitFeb 4 2014, 8:22 PM

Change 110299 merged by jenkins-bot:
Made ActiveUsers use querycache and do staggered updates on view

https://gerrit.wikimedia.org/r/110299

gerritbot added a comment.Via ConduitFeb 4 2014, 8:43 PM

Change 111258 had a related patch set uploaded by Aaron Schulz:
Made ActiveUsers use querycache and do staggered updates on view

https://gerrit.wikimedia.org/r/111258

gerritbot added a comment.Via ConduitFeb 4 2014, 8:48 PM

Change 111258 merged by jenkins-bot:
Made ActiveUsers use querycache and do staggered updates on view

https://gerrit.wikimedia.org/r/111258

Add Comment

Column Prototype
This is a very early prototype of a persistent column. It is not expected to work yet, and leaving it open will activate other new features which will break things. Press "\" (backslash) on your keyboard to close it now.