Page MenuHomePhabricator

[Regression] user rights log entries no longer include expiry
Closed, ResolvedPublicBUG REPORT

Description

Steps to Reproduce:
Add a user to a user group temporarily

Actual Results:
Log entry says that they were added to the group

Expected Results:
Log entry says that they were added to the group, and notes the expiry

Examples:

bot was only added for a week, but the expiration isn't noted

This is for new log entries: https://www.wikidata.org/wiki/Special:UserRights/DannyS712 still shows expiries, but newly created entries do not have the expiry included in their parameters:

Recent log entry
MariaDB [simplewiktionary_p]> SELECT * FROM logging WHERE log_id = 89109;
+--------+----------+------------+----------------+-----------+---------------+-----------+----------------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------+----------+
| log_id | log_type | log_action | log_timestamp  | log_actor | log_namespace | log_title | log_comment_id | log_params                                                                                                                                                                                                                     | log_deleted | log_page |
+--------+----------+------------+----------------+-----------+---------------+-----------+----------------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------+----------+
|  89109 | rights   | rights     | 20200612233509 |         4 |             2 | DannyS712 |         337788 | a:4:{s:12:"4::oldgroups";a:1:{i:0;s:10:"rollbacker";}s:12:"5::newgroups";a:2:{i:0;s:10:"rollbacker";i:1;s:3:"bot";}s:11:"oldmetadata";a:1:{i:0;a:1:{s:6:"expiry";N;}}s:11:"newmetadata";a:2:{i:0;a:1:{s:6:"expiry";N;}i:1;N;}} |           0 |        0 |
+--------+----------+------------+----------------+-----------+---------------+-----------+----------------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------+----------+

Note the

old log entry
MariaDB [wikidatawiki_p]> SELECT * FROM logging WHERE log_id = 662125900;
+-----------+----------+------------+----------------+-----------+---------------+-----------+----------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------+----------+
| log_id    | log_type | log_action | log_timestamp  | log_actor | log_namespace | log_title | log_comment_id | log_params                                                                                                                                                                                                                                                              | log_deleted | log_page |
+-----------+----------+------------+----------------+-----------+---------------+-----------+----------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------+----------+
| 662125900 | rights   | rights     | 20190725202501 |      1105 |             2 | DannyS712 |              3 | a:4:{s:12:"4::oldgroups";a:1:{i:0;s:10:"rollbacker";}s:12:"5::newgroups";a:2:{i:0;s:10:"rollbacker";i:1;s:5:"flood";}s:11:"oldmetadata";a:1:{i:0;a:1:{s:6:"expiry";N;}}s:11:"newmetadata";a:2:{i:0;a:1:{s:6:"expiry";N;}i:1;a:1:{s:6:"expiry";s:14:"20190801202501";}}} |           0 | 59543586 |
+-----------+----------+------------+----------------+-----------+---------------+-----------+----------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------+----------+

Event Timeline

Restricted Application added a project: User-DannyS712. · View Herald TranscriptJun 13 2020, 2:33 AM
Restricted Application added a subscriber: Aklapper. · View Herald Transcript
DannyS712 moved this task from Unsorted to Reports on the User-DannyS712 board.Jun 13 2020, 2:33 AM
DannyS712 renamed this task from [Regression] user rights log entries no longer show expiry to [Regression] user rights log entries no longer include.Jun 13 2020, 2:42 AM
DannyS712 updated the task description. (Show Details)
Restricted Application added a subscriber: Liuxinyu970226. · View Herald TranscriptJun 13 2020, 2:42 AM
DannyS712 renamed this task from [Regression] user rights log entries no longer include to [Regression] user rights log entries no longer include expiry.Jun 13 2020, 2:42 AM
DannyS712 triaged this task as High priority.Jun 13 2020, 2:44 AM
DannyS712 added a project: Community-Tech.

Tagging CPT per recent work on user group management and community tech per original T12493: Setting a temporary usergroup (allow expiry of user rights via Special:UserRights form)

DannyS712 added a comment.EditedJun 13 2020, 2:49 AM

Logging was moved as part of T234921: Factor group membership management out of User class - many recent patches on top of that, not easy to revert

However, does not appear to have been caused by 40b88d635be6c4c00150b56443dafd5bdef0dd16:

$ git checkout 08dae812d03e857f31cc0fd6799a4d1f139e3488 (previous commit)
-confirmed to still be working
$ git checkout 40b88d635be6c4c00150b56443dafd5bdef0dd16 (potential cause)
-confirmed to still be working

Luckily the expiry is actually inserted, so this is the issue with the log entry:

use simplewiktionary_p;
SELECT * FROM user_groups WHERE ug_user = 25647;

ug_user	ug_group	ug_expiry
25647	bot	20200619233509
...
DannyS712 added a comment.EditedJun 13 2020, 3:20 AM

Luckily the expiry is actually inserted, so this is the issue with the log entry:

use simplewiktionary_p;
SELECT * FROM user_groups WHERE ug_user = 25647;

ug_user	ug_group	ug_expiry
25647	bot	20200619233509
...

Yes, the expiry is saved, but the log entry is wrong
(we should get a list of all current temporary user group assignments so that the log entries can be filled in later via script?)

I checked-out master and added a temporary group - still works, same with current version of core deployed to simplewiktionary. Could another extension be causing this?

SpecialUserrights::doSaveUserGroups includes some wfDebug calls with information that includes what may be logged - can someone check if the lines:

wfDebug( 'oldGroups: ' . print_r( $oldGroups, true ) );
wfDebug( 'newGroups: ' . print_r( $newGroups, true ) );
wfDebug( 'oldUGMs: ' . print_r( $oldUGMs, true ) );
wfDebug( 'newUGMs: ' . print_r( $newUGMs, true ) );

include the expiry in the UGMs?

The most recent log entry with an expiry that I can find on enwiki is from 11 June

This appears to have been after the the train bumped in to wmf.36 (all wikis to 1.35.0-wmf.36 merged at 12:58 PM, log entry is from 5:06 PM)

Two things I've found that is probably gonna cause us some trouble, but it's not the root cause of this bug:

  1. Now deprecated User::addGroup should pass 'true' as '$allowUpdate' parameter into the UserGroupManager
  2. Another thing that might bite us is that before the cached memberships were updated in place, now the in place update semantics was dropped for simplicity. However, now after adding a group membership we are trying to read it back from the database immediately - that might fail due to replication lag. We need to update the caches in place without dropping the caches entirely on user group membership addition/deletion
DannyS712 added a comment.EditedJun 13 2020, 5:07 AM

I looked at the recent user rights log entries on all public wikis, and found:
P11488 - expirations that weren't logged (able to find the expiration for all but 2 of the entries)
For incubatorwiki, we can narrow down the change in whether expiration was logged to between 11:44, 10 June 2020 and 13:10, 10 June 2020, which suggests it may have been caused by the train[1]
Expirations were logged when they were part of a user's old groups, just not the new ones (see, eg, DannyS712@simplewiktionary or Equoreo@itwiki)

I'll try to keep P11488 updated with enwiki rights entries, which make up almost all of the temporary rights assignments that I found; hopefully we can write a script to fill these back in at some point

[1] See https://incubator.wikimedia.org/wiki/Special:Log/rights?limit=10

Change 605359 had a related patch set uploaded (by Ppchelko; owner: Ppchelko):
[mediawiki/core@master] Followups for UserGroupManager

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

Change 605359 merged by jenkins-bot:
[mediawiki/core@master] Followups for UserGroupManager

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

DannyS712 added a comment.EditedJun 19 2020, 10:15 AM

Appears to have been fixed? https://en.wikiversity.org/wiki/Special:UserRights/MJ1735 entry from 02:30, 19 June 2020 includes the expiry

Edit: predated by https://en.wikipedia.org/w/index.php?title=Special:Log&logid=109073287 at 20:58, 18 June 2020 on enwiki

Pchelolo closed this task as Resolved.Jun 19 2020, 1:10 PM
Pchelolo claimed this task.
Pchelolo moved this task from Inbox to Done on the Platform Team Workboards (Clinic Duty Team) board.

@Pchelolo should a script be written to back-fill the expirations?