Assuming this is a Wikimedia-production-error ( https://phabricator.wikimedia.org/maniphest/task/edit/form/46/ )

Looking at logstash Call to a member function getName() on null would seem to be the main cuplrit.

This is the associated stacktrace:

from /srv/mediawiki/php-1.44.0-wmf.17/extensions/GrowthExperiments/includes/Mentorship/ChangeMentor.php(185)
#0 /srv/mediawiki/php-1.44.0-wmf.17/includes/deferred/MWCallableUpdate.php(52): GrowthExperiments\Mentorship\ChangeMentor->GrowthExperiments\Mentorship\{closure}(string)
#1 /srv/mediawiki/php-1.44.0-wmf.17/includes/deferred/DeferredUpdates.php(459): MediaWiki\Deferred\MWCallableUpdate->doUpdate()
#2 /srv/mediawiki/php-1.44.0-wmf.17/includes/deferred/DeferredUpdates.php(201): MediaWiki\Deferred\DeferredUpdates::attemptUpdate(MediaWiki\Deferred\MWCallableUpdate)
#3 /srv/mediawiki/php-1.44.0-wmf.17/includes/deferred/DeferredUpdates.php(288): MediaWiki\Deferred\DeferredUpdates::run(MediaWiki\Deferred\MWCallableUpdate)
#4 /srv/mediawiki/php-1.44.0-wmf.17/includes/deferred/DeferredUpdatesScope.php(243): MediaWiki\Deferred\DeferredUpdates::MediaWiki\Deferred\{closure}(MediaWiki\Deferred\MWCallableUpdate, int)
#5 /srv/mediawiki/php-1.44.0-wmf.17/includes/deferred/DeferredUpdatesScope.php(172): MediaWiki\Deferred\DeferredUpdatesScope->processStageQueue(int, int, Closure)
#6 /srv/mediawiki/php-1.44.0-wmf.17/includes/deferred/DeferredUpdates.php(307): MediaWiki\Deferred\DeferredUpdatesScope->processUpdates(int, Closure)
#7 /srv/mediawiki/php-1.44.0-wmf.17/extensions/EventBus/includes/JobExecutor.php(110): MediaWiki\Deferred\DeferredUpdates::doUpdates()
#8 /srv/mediawiki/rpc/RunSingleJob.php(60): MediaWiki\Extension\EventBus\JobExecutor->execute(array)
#9 {main}

Change #1122167 had a related patch set uploaded (by Michael Große; author: Michael Große):

[mediawiki/extensions/GrowthExperiments@master] fix(Mentorship): Don't fail notification if old mentor is null

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

@Michael noted on the patch: // TODO: Figure out how the old mentor could be null and what should be done in that cae. This had a short conversation on Gerrit:

In Gerrit, @Urbanecm_WMF wrote:

I think that can happen if the user had no mentor assigned (for example, because they registered before GrowthExperiments deployment and they never visited Special:Homepage).

In Gerrit, @Michael wrote:

That's one half of it. The other half of the question is how we would encounter this code-path for them?
Based on logstash, it seems there was a short burst of these errors. Looking where this method is called, this seems to be coming from either ReassignMentees (unlikely, as they never had a mentor, so there's nothing to reassign), SpecialClaimMentee (also somewhat unlikely, did someone claim a lot of Mentees in a very short time?), or ApiSetMentor.
Of these, the ApiSetMentee seems the most plausible to me? Still, I'm unsure what the intention and expected behavior is here.
We could reintroduce the reason field? Though the i18n message key makes it look like that the related message of growthexperiments-notification-body-mentor-change that made use of it was intended to be removed eventually?

I'm moving it the conversation to Phabricator, as it is getting more general than what is in scope for code review discussions:

We could reintroduce the reason field? Though the i18n message key makes it look like that the related message of growthexperiments-notification-body-mentor-change that made use of it was intended to be removed eventually?

I'm not 100% sure how the reason field would be helpful here. We explicitly decided on not exposing the reason to the mentee, see the conversation in T327493. The field has to be processed by the presentation model for B/C reasons. Unfortunately, we need to basically keep the B/C layer in indefinitely. Echo is capable of showing up to 2000 notifications per user. When was the oldest notification generated depends on how many notifications the user has. If they are not particularly active, the 2000th oldest notification might be very old (possibly including the reason field).

It might be a good idea to switch to a time-based expiry (T383948). That would allow us to assume any notification older than N days is no longer present in the database, and thus no user can possibly see it. With the current offset-based approach, we do not have the certainty, and we need to be able to render notifications with reason basically forever.

The other half of the question is how we would encounter this code-path for them?

Good question! As far as I can see, all occurrences were on a job runner. The only place where ChangeMentor is called from a job context is ReassignMentees. I agree it seems unlikely (and almost impossible), but it is the only job calling this place. Another interesting observation is that while there were hundreds of notices, all of them came from a single request (reqId 64e175a4-3845-472d-9299-1d4564d1f5aa). This means that only one job failed (rather than a job failing regularly), and that we are dealing with some kind of an edge case.

A very good question is how did ``ReassignMentees get called on someone that does not have any mentor. A possible theory for that:

• In normal circumstances, ReassignMentees calls ChangeMentor to change the mentor from user A to user B. However, it is _also_ capable of dropping the mentee/mentor relationship altogether. This happens when a wiki has no suitable mentor to assign to an user (MentorManager::getRandomAutoAssignedMentor() returns null). If that happens, ReassignMentees calls MentorStore::dropMenteeRelationship() rather than ChangeMentor.
• ReassignMenteesJob reassigns up to GEMentorshipReassignMenteesBatchSize mentees in one go. If a mentor has more mentees than that, a follow-up job is scheduled. This creates a non-zero possibility that ReassignMenteesJob goes trough one mentee twice (due to a race condition of some kind).
• If ReassignMenteesJob drops a mentor for user A, a race condition causes ReassignMenteesJob to process user A _again_ and the second execution manages to find the mentor (which had to fail during the first pass), then we could observe what we are seeing.

However, this is a lot of conditions at once, and it all feels unlikely to happen. I also can't really explain how the race condition could have happened hundreds of times during a single job. Maybe not all of the circumstances I listed above are strictly necessary, and it is possible to achieve something similar in situations that are more likely to happen?

Hopefully this provides some extra thoughts on how this might happen, and where to go with debugging. It might be useful to take a look at all logs from that reqId (we wouldn't have debug logs, but at least something should be logged). Hope this helps!

Thank you for these additional thoughts! I've updated the change in the manner we discussed elsewhere.

Change #1122167 merged by jenkins-bot:

[mediawiki/extensions/GrowthExperiments@master] fix(Mentorship): Don't fail notification if old mentor is null

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

QA Note: the issue fixed here is likely to only occur in a rare race-condition. Probably not something that can be produced deliberately. The main thing to check would probably be that the notifications received by mentees when their mentor changes still look the same.