Page MenuHomePhabricator

DBPerformance warning for "DELETE .. echo_email_batch" query from MWEchoEmailBatch
Closed, DeclinedPublicPRODUCTION ERROR

Description

Query affected 15865 row(s):
query-m: DELETE FROM `echo_email_batch` WHERE eeb_user_id = 'X' AND (eeb_event_id <= N)
TransactionProfiler.php line 192 calls wfBacktrace()
Database.php line 856 calls TransactionProfiler->recordQueryCompletion()
Database.php line 2256 calls DatabaseBase->query()
EmailBundler.php line 308 calls DatabaseBase->delete()
EmailBundler.php line 230 calls MWEchoEmailBundler->clearProcessedEvent()
NotificationEmailBundleJob.php line 19 calls MWEchoEmailBundler->processBundleEmail()
JobRunner.php line 265 calls MWEchoNotificationEmailBundleJob->run()
JobRunner.php line 179 calls JobRunner->executeJob()
RunJobs.php line 47 calls JobRunner->run()

Event Timeline

aaron created this task.May 20 2016, 3:55 AM
Restricted Application added subscribers: Zppix, Aklapper. · View Herald TranscriptMay 20 2016, 3:55 AM
aaron removed aaron as the assignee of this task.May 20 2016, 3:55 AM
ori moved this task from Inbox to Radar on the Performance-Team board.Jun 6 2016, 5:59 PM
Krinkle moved this task from Unsorted to Cleanup on the Technical-Debt board.
Krinkle added a subscriber: Krinkle.Apr 5 2017, 9:56 PM

Related:

Class MWEchoEmailBundler no longer exists. Similar code now lives in MWEchoEmailBatch, which despite major refactoring still appears to have a mostly identical clearProcessedEvent method that does indeed still not use batches.

https://github.com/wikimedia/mediawiki-extensions-Echo/blob/24f8f151/includes/EmailBatch.php#L230

Krinkle updated the task description. (Show Details)EditedJul 12 2017, 7:22 PM

The new "Sub-optimal transaction" warnings (level=INFO for now) are picking up this issue in production.

The warning is about queries spending 4-10 seconds within a single transaction.

https://logstash.wikimedia.org/goto/97274c301267b8f7218ac41ef7ce6ddb

channel=DBPerformance level=INFO url=/rpc/RunJobs.php
Sub-optimal transaction on DB(s) [10.64.0.205 (mediawikiwiki) (TRX#44a0e2)]: 
0	0.000447	query-m: INSERT IGNORE INTO `echo_email_batch` (eeb_user_id,eeb_event_id,eeb_event_priority,eeb_event_hash) VALUES ('X') [TRX#44a0e2]
1	19.807544	...delay...

Sub-optimal transaction on DB(s) [10.64.0.205 (mediawikiwiki) (TRX#284375)]: 
0	0.000419	query-m: INSERT IGNORE INTO `echo_email_batch` (eeb_user_id,eeb_event_id,eeb_event_priority,eeb_event_hash) VALUES ('X') [TRX#284375]
1	1.182120	...delay...
2	0.278809	query: SELECT * FROM `echo_notification` LEFT JOIN `echo_event` ON ((notification_event=event_id)) WHERE notification_user = 'X' ORDER BY notification_timestamp DESC LIMIT N  [TRX#60bf1d]
3	0.000452	query-m: INSERT IGNORE INTO `echo_email_batch` (eeb_user_id,eeb_event_id,eeb_event_priority,eeb_event_hash) VALUES ('X') [TRX#284375]
4	9.330066	...delay...
5	0.000486	query-m: INSERT IGNORE INTO `echo_email_batch` (eeb_user_id,eeb_event_id,eeb_event_priority,eeb_event_hash) VALUES ('X') [TRX#284375]
6	2.411176	...delay...

Sub-optimal transaction on DB(s) [10.64.0.205 (mediawikiwiki) (TRX#fbba2c)]: 
0	0.021751	query-m: INSERT IGNORE INTO `echo_email_batch` (eeb_user_id,eeb_event_id,eeb_event_priority,eeb_event_hash) VALUES ('X') [TRX#fbba2c]
1	4.485253	...delay...
Krinkle renamed this task from MWEchoEmailBundler should batch updates to MWEchoEmailBatch should batch write queries.Jun 5 2018, 1:33 AM
Krinkle changed Risk Rating from N/A to default.
Restricted Application added a project: Growth-Team. · View Herald TranscriptSep 12 2018, 10:39 PM
Krinkle renamed this task from MWEchoEmailBatch should batch write queries to DBPerformance warning for "DELETE .. echo_email_batch" query from MWEchoEmailBatch.Sep 12 2018, 10:43 PM
Krinkle closed this task as Declined.Sep 12 2018, 10:47 PM

Not seen in Logstash for at least 30 days.

mmodell changed the subtype of this task from "Task" to "Production Error".Aug 28 2019, 11:11 PM