Page MenuHomePhabricator
Create Task
Maniphest T368289

Incredible amount of logs from Wikimedia\Rdbms\LoadBalancer::runPrimaryTransactionIdleCallbacks
Open, In Progress, HighPublic
Actions

Description

During connectivity issues in production, these logs are generated at incredible volumes.

June 22 2024 22:00 UTC to June 23 2024 05:30 UTC for message:"found writes pending"

CountNormalized message
18,375,432Wikimedia\Rdbms\LoadBalancer::runPrimaryTransactionIdleCallbacks: found writes pending ().
11,027,272Wikimedia\Rdbms\LoadBalancer::runPrimaryTransactionIdleCallbacks: found writes pending (MediaWiki\Deferred\LinksUpdate\LinksUpdate::acquirePageLock).
5,145,993Wikimedia\Rdbms\LoadBalancer::runPrimaryTransactionIdleCallbacks: found writes pending (CategoryMembershipChangeJob::run).
2,841,780Wikimedia\Rdbms\LoadBalancer::runPrimaryTransactionIdleCallbacks: found writes pending (MediaWiki\Linter\Database::setForPage).
2,167,911Wikimedia\Rdbms\LoadBalancer::runPrimaryTransactionIdleCallbacks: found writes pending (MediaWiki\Deferred\LinksUpdate\LinksUpdate::updateLinksTimestamp, MediaWiki\Deferred\LinksUpdate\LinksUpdate::acquirePageLock, MediaWiki\Deferred\LinksUpdate\LinksUpdate
......

Details

Related Changes in Gerrit:
SubjectRepoBranchLines +/-
rdbms: add StatsLib counter for danging writes during post-transaction callbacksmediawiki/coremaster+3 -0
rdbms: Reduce log severity of "found writes pending"mediawiki/coreREL1_42+1 -1
rdbms: only mention write queries in "writes pending" warningsmediawiki/coreREL1_42+1 -1
rdbms: only mention write queries in "writes pending" warningsmediawiki/coremaster+1 -1
rdbms: Reduce log severity of "found writes pending"mediawiki/corewmf/1.43.0-wmf.11+1 -1
rdbms: Reduce log severity of "found writes pending"mediawiki/coremaster+1 -1
rdbms: Reduce log severity of "found writes pending"mediawiki/corewmf/1.43.0-wmf.10+1 -1
Customize query in gerrit

Related Objects
Search...

Event Timeline

colewhite created this task.Jun 24 2024, 3:46 PM
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptJun 24 2024, 3:46 PM
colewhite triaged this task as High priority.Jun 24 2024, 3:46 PM
colewhite added a parent task: T368098: Dumps generation cause disruption to the production environment.
gerritbot added a comment.Jun 24 2024, 4:24 PM

Change #1049228 had a related patch set uploaded (by Ladsgroup; author: Amir Sarabadani):

[mediawiki/core@master] rdbms: Reduce log severity of "found writes pending"

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

gerritbot added a project: Patch-For-Review.Jun 24 2024, 4:24 PM
hashar updated the task description. (Show Details)Jun 24 2024, 4:27 PM
Ladsgroup claimed this task.Jun 24 2024, 4:31 PM
Ladsgroup added a project: MediaWiki-libs-Rdbms.
aaron added a project: MW-Interfaces-Team.Jun 24 2024, 5:39 PM
aaron changed the task status from Open to In Progress.Jun 24 2024, 5:54 PM
aaron moved this task from Incoming (Needs Triage) to In Progress on the MW-Interfaces-Team board.
gerritbot added a comment.Jun 24 2024, 8:11 PM

Change #1049261 had a related patch set uploaded (by Ladsgroup; author: Amir Sarabadani):

[mediawiki/core@wmf/1.43.0-wmf.10] rdbms: Reduce log severity of "found writes pending"

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

gerritbot added a comment.Jun 24 2024, 8:34 PM

Change #1049261 merged by jenkins-bot:

[mediawiki/core@wmf/1.43.0-wmf.10] rdbms: Reduce log severity of "found writes pending"

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

ReleaseTaggerBot added a project: MW-1.43-notes (1.43.0-wmf.10; 2024-06-18).Jun 24 2024, 9:00 PM
MatthewVernon subscribed.Jun 25 2024, 10:25 AM
dr0ptp4kt subscribed.Jun 25 2024, 6:27 PM
gerritbot added a comment.Jun 25 2024, 8:37 PM

Change #1049228 merged by jenkins-bot:

[mediawiki/core@master] rdbms: Reduce log severity of "found writes pending"

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

ReleaseTaggerBot edited projects, added MW-1.43-notes (1.43.0-wmf.12; 2024-07-02); removed MW-1.43-notes (1.43.0-wmf.10; 2024-06-18).Jun 25 2024, 9:00 PM
Maintenance_bot removed a project: Patch-For-Review.Jun 25 2024, 9:30 PM
gerritbot added a comment.Jun 26 2024, 11:47 AM

Change #1049909 had a related patch set uploaded (by Ladsgroup; author: Amir Sarabadani):

[mediawiki/core@wmf/1.43.0-wmf.11] rdbms: Reduce log severity of "found writes pending"

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

gerritbot added a project: Patch-For-Review.Jun 26 2024, 11:47 AM
gerritbot added a comment.Jun 26 2024, 12:15 PM

Change #1049909 merged by jenkins-bot:

[mediawiki/core@wmf/1.43.0-wmf.11] rdbms: Reduce log severity of "found writes pending"

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

Maintenance_bot removed a project: Patch-For-Review.Jun 26 2024, 12:31 PM
xcollazo subscribed.Jun 26 2024, 12:34 PM
ReleaseTaggerBot edited projects, added MW-1.43-notes (1.43.0-wmf.11; 2024-06-25); removed MW-1.43-notes (1.43.0-wmf.12; 2024-07-02).Jun 26 2024, 1:00 PM
Ladsgroup added a comment.Jun 26 2024, 3:47 PM

I've been trying to debug and demystify what caused this. Here are some preliminary notes:

colewhite added a comment.EditedJun 26 2024, 5:59 PM

FTR, after https://gerrit.wikimedia.org/r/c/operations/puppet/+/1048863 we dropped 99% of "found writes pending" logs randomly as they appeared from Kafka. I have deleted no ingested logs.

According to the Kafka topic, we got around 560,778 logs per second (src). This doesn't specifically select just "found writes pending" logs, but the udp_localhost-warning topic doesn't get a lot of traffic.

Ladsgroup added a comment.Jun 28 2024, 6:44 PM

Given that 99% of the logs were dropped, it mean each job triggered 1000 "writes pending found" log. The only explanation is that it fell into an infinite loop when databases got lagged or slow. That part is not fixed yet and should be investigated further.

gerritbot added a comment.Jul 2 2024, 2:49 AM

Change #1051229 had a related patch set uploaded (by Aaron Schulz; author: Aaron Schulz):

[mediawiki/core@master] rdbms: cleanup transaction write query tracking and reporting

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

gerritbot added a project: Patch-For-Review.Jul 2 2024, 2:49 AM
aaron mentioned this in T372169: Refactor NameTableStore to avoid complex onAtomicSectionCancel() callback.Aug 9 2024, 6:59 PM
gerritbot added a comment.Aug 21 2024, 4:20 PM

Change #1064410 had a related patch set uploaded (by Aaron Schulz; author: Aaron Schulz):

[mediawiki/core@master] rdbms: only mention write queries in "writes pending" warnings

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

Krinkle moved this task from Untriaged to Rdbms library on the MediaWiki-libs-Rdbms board.Aug 30 2024, 1:06 AM
gerritbot added a comment.Aug 30 2024, 1:32 AM

Change #1064410 merged by jenkins-bot:

[mediawiki/core@master] rdbms: only mention write queries in "writes pending" warnings

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

ReleaseTaggerBot edited projects, added MW-1.43-notes (1.43.0-wmf.21; 2024-09-03); removed MW-1.43-notes (1.43.0-wmf.11; 2024-06-25).Aug 30 2024, 2:00 AM
HCoplin-WMF subscribed.Oct 1 2024, 4:36 PM

@Ladsgroup -- do you need anything else from the MWI team on this? Or are you taking it from here? If the later, can we remove our team tag?

Ladsgroup added a comment.Oct 2 2024, 11:29 AM
In T368289#10192880, @HCoplin-WMF wrote:

@Ladsgroup -- do you need anything else from the MWI team on this? Or are you taking it from here? If the later, can we remove our team tag?

We fixed the issue by reducing the log severity level but it was very likely that it ended up in an infinite loop until it got killed. And that was not fully investigated. So far we haven't seen it again, so maybe let's close and then reopen if it happens again.

HCoplin-WMF added a subscriber: aaron.Oct 2 2024, 12:18 PM

That seems reasonable. @aaron -- any concerns with closing for now?

aaron added a comment.Oct 7 2024, 8:15 PM
In T368289#10195606, @HCoplin-WMF wrote:

That seems reasonable. @aaron -- any concerns with closing for now?

I suppose we could try enabling the logging again and see if it re-occurs.

gerritbot added a comment.Oct 7 2024, 8:36 PM

Change #1078474 had a related patch set uploaded (by Paladox; author: Amir Sarabadani):

[mediawiki/core@REL1_42] rdbms: Reduce log severity of "found writes pending"

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

gerritbot added a comment.Oct 7 2024, 8:38 PM

Change #1078475 had a related patch set uploaded (by Paladox; author: Aaron Schulz):

[mediawiki/core@REL1_42] rdbms: only mention write queries in "writes pending" warnings

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

gerritbot added a comment.Oct 8 2024, 12:14 PM

Change #1078474 merged by jenkins-bot:

[mediawiki/core@REL1_42] rdbms: Reduce log severity of "found writes pending"

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

gerritbot added a comment.Oct 8 2024, 12:14 PM

Change #1078475 merged by jenkins-bot:

[mediawiki/core@REL1_42] rdbms: only mention write queries in "writes pending" warnings

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

Ladsgroup added a comment.Oct 8 2024, 12:43 PM
In T368289#10208240, @aaron wrote:
In T368289#10195606, @HCoplin-WMF wrote:

That seems reasonable. @aaron -- any concerns with closing for now?

I suppose we could try enabling the logging again and see if it re-occurs.

That brought down all wikis multiple times, I don't think it's safe to revert it and see if all wikis go down. You can do stat or something else instead.

ReleaseTaggerBot added a project: MW-1.42-notes.Oct 8 2024, 2:01 PM
aaron lowered the priority of this task from High to Medium.Nov 7 2024, 4:48 PM
aaron moved this task from In Progress to Backlog (Triaged and Ready) on the MW-Interfaces-Team board.
HCoplin-WMF moved this task from Backlog (Triaged and Ready) to In Progress on the MW-Interfaces-Team board.Dec 4 2024, 2:16 PM
HCoplin-WMF moved this task from In Progress to Backlog (Triaged and Ready) on the MW-Interfaces-Team board.
aaron moved this task from Backlog (Triaged and Ready) to MWI-Sprint-6 (2025-03-25 to 2025-04-08) on the MW-Interfaces-Team board.Apr 2 2025, 3:14 PM
aaron edited projects, added MW-Interfaces-Team (MWI-Sprint-6 (2025-03-25 to 2025-04-08)); removed MW-Interfaces-Team.
aaron moved this task from Committed to In Progress on the MW-Interfaces-Team (MWI-Sprint-6 (2025-03-25 to 2025-04-08)) board.
daniel raised the priority of this task from Medium to High.Apr 4 2025, 7:27 AM
HCoplin-WMF edited projects, added MW-Interfaces-Team; removed MW-Interfaces-Team (MWI-Sprint-6 (2025-03-25 to 2025-04-08)).Apr 8 2025, 3:19 PM
HCoplin-WMF moved this task from Incoming (Needs Triage) to Next Up on the MW-Interfaces-Team board.Apr 8 2025, 3:34 PM
aaron mentioned this in T391364: [SPIKE] Add a statslib counter for the LoadBalancer::runPrimaryTransactionIdleCallbacks errors.Apr 11 2025, 6:10 PM
gerritbot added a comment.Apr 16 2025, 4:58 PM

Change #1137040 had a related patch set uploaded (by Aaron Schulz; author: Aaron Schulz):

[mediawiki/core@master] rdbms: add StatsLib counter for danging writes during post-transaction callbacks

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

gerritbot added a comment.Apr 26 2025, 11:58 PM

Change #1137040 merged by jenkins-bot:

[mediawiki/core@master] rdbms: add StatsLib counter for danging writes during post-transaction callbacks

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

HCoplin-WMF moved this task from Next Up to Backlog (Triaged and Ready) on the MW-Interfaces-Team board.Apr 29 2025, 1:38 PM
aaron mentioned this in T392913: [SPIKE] Investigate risks of logging LoadBalancer::runPrimaryTransactionIdleCallbacks errors again.Apr 29 2025, 3:31 PM
HCoplin-WMF closed subtask T391364: [SPIKE] Add a statslib counter for the LoadBalancer::runPrimaryTransactionIdleCallbacks errors as Resolved.May 20 2025, 4:34 PM
Atieno moved this task from Backlog (Triaged and Ready) to Radar (other teams work) on the MW-Interfaces-Team board.Nov 14 2025, 9:59 AM
Content licensed under Creative Commons Attribution-ShareAlike (CC BY-SA) 4.0 unless otherwise noted; code licensed under GNU General Public License (GPL) 2.0 or later and other open source licenses. By using this site, you agree to the Terms of Use, Privacy Policy, and Code of Conduct. · Wikimedia Foundation · Privacy Policy · Code of Conduct · Terms of Use · Disclaimer · CC-BY-SA · GPL · Credits