@Nikki reported on the translatewiki.net channel that some action=translations requests are slow in translatewiki (e.g. >5 seconds)
First we inspected the times keys in the API response, but they did not have any especially slow parts.
Manually debugging such request revealed more clues:
[2024-09-05T10:15:13.860128+00:00] wfDebug.DEBUG: Start request GET /w/api.php?action=translationaids&format=json&title=MediaWiki%3ATuesday%2Fde&uselang=en-gb # Request setup follows by loading message groups [2024-09-05T10:15:13.904334+00:00] memcached.DEBUG: MemCache: got WANCache:translatewiki_net-bw_:translate-mg:aggregate-groups|#|v [] [] [2024-09-05T10:15:13.904401+00:00] memcached.DEBUG: MemCache: got WANCache:translatewiki_net-bw_:translate-mg:aggregate-groups|#|t [] [] [2024-09-05T10:15:13.909812+00:00] memcached.DEBUG: MemCache: got WANCache:translatewiki_net-bw_:translate-mg:file-based-groups|#|v [] [] [2024-09-05T10:15:13.909893+00:00] memcached.DEBUG: MemCache: got WANCache:translatewiki_net-bw_:translate-mg:file-based-groups|#|t [] [] [2024-09-05T10:15:13.921711+00:00] memcached.DEBUG: MemCache: got WANCache:translatewiki_net-bw_:translate-mg:hook-defined-groups|#|v [] [] [2024-09-05T10:15:13.921816+00:00] memcached.DEBUG: MemCache: got WANCache:translatewiki_net-bw_:translate-mg:hook-defined-groups|#|t [] [] [2024-09-05T10:15:13.922394+00:00] memcached.DEBUG: MemCache: got WANCache:translatewiki_net-bw_:translate-mg:message-bundles|#|v [] [] [2024-09-05T10:15:13.922440+00:00] memcached.DEBUG: MemCache: got WANCache:translatewiki_net-bw_:translate-mg:message-bundles|#|t [] [] [2024-09-05T10:15:13.922755+00:00] rdbms.DEBUG: Wikimedia\Rdbms\LoadBalancer::reuseOrOpenConnectionForNewRef: reusing connection for 0/translatewiki_net-bw_ [] [] [2024-09-05T10:15:13.923741+00:00] memcached.DEBUG: MemCache: got WANCache:translatewiki_net-bw_:translate-mg:translatable-pages|#|v [] [] [2024-09-05T10:15:13.923807+00:00] memcached.DEBUG: MemCache: got WANCache:translatewiki_net-bw_:translate-mg:translatable-pages|#|t [] [] # Soon after that a lof of blogs are loaded from cache [2024-09-05T10:15:14.049443+00:00] memcached.DEBUG: MemCache: got WANCache:global:SqlBlobStore-blob:translatewiki_net-bw_:tt%3A11296735|#|v [] [] (repeated many times with different ids) # Then bunch of Localizations are loaded, for all custom languages? [2024-09-05T10:15:14.155694+00:00] localisation.DEBUG: LocalisationCache::loadCoreData: got localisation for abr from source [] [] [...] [2024-09-05T10:15:14.298275+00:00] localisation.DEBUG: LocalisationCache::loadCoreData: got localisation for zmi from source [] [] # Then we start processing machine translation requests, look at the timestamps! [2024-09-05T10:15:14.301996+00:00] memcached.DEBUG: get(translatewiki_net-bw_:translate-service-Google) [] [] [2024-09-05T10:15:14.302273+00:00] memcached.DEBUG: get(translatewiki_net-bw_:translate-tmsug-pairs-Google) [] [] [...] [2024-09-05T10:15:20.357548+00:00] memcached.DEBUG: get(translatewiki_net-bw_:translate-tmsug-pairs-MinT) [] [] [2024-09-05T10:15:20.367796+00:00] memcached.DEBUG: MemCache: sock i:0; got translatewiki_net-bw_:translate-tmsug-pairs-MinT [] [] # Some more stuff and shutdown happens a bit later [2024-09-05T10:15:21.252885+00:00] session.DEBUG: Saving all sessions on shutdown [] []
The low hanging fruit here is that the tmsug-pairs-Apertium/Mint key is called thousands of times (and in case of MinT, the value is quite large) causing majority of the slowdown.