Also seen for CheckUser on 9 September 2023 around 1,000 times ( https://logstash.wikimedia.org/goto/93005cede3fa74c279b10de190c3a72a ).

Mentioned in SAL (#wikimedia-operations) [2023-09-21T17:49:35Z] <ladsgroup@cumin1001> dbctl commit (dc=all): 'Depool db2149 (T346365)', diff saved to https://phabricator.wikimedia.org/P52558 and previous config saved to /var/cache/conftool/dbconfig/20230921-174934-ladsgroup.json

Mentioned in SAL (#wikimedia-operations) [2023-09-21T17:56:34Z] <ladsgroup@cumin1001> dbctl commit (dc=all): 'Depool db1166 (T346365)', diff saved to https://phabricator.wikimedia.org/P52560 and previous config saved to /var/cache/conftool/dbconfig/20230921-175634-ladsgroup.json

Mentioned in SAL (#wikimedia-operations) [2023-09-21T18:00:04Z] <ladsgroup@cumin1001> dbctl commit (dc=all): 'Repool db1166 (T346365)', diff saved to https://phabricator.wikimedia.org/P52561 and previous config saved to /var/cache/conftool/dbconfig/20230921-180003-ladsgroup.json

Looking at this more closely...

The data from etcd in its (almost) raw form can be seen at https://noc.wikimedia.org/dbconfig/eqiad.json. There we see that both sectionLoads and groupLoadsBySection contain a key for the default section is present, and that key named DEFAULT. In other words, it's not called something else (e.g. "s3") and it is not absent.

This data is processed in two places:

1. Once during all web requests and CLI processes from CommonSettings.php, where we massage this data together with data from wmf-config/db-production into $wgLBFactoryConf.
2. Possibly a second time in $wmgLBFactoryConfigCallback, as triggered periodicaly by long-runnig CLI maintenance scripts via Maintenance->waitForReplication and LBFactory->autoReconfigure.

Looking at the two, I don't see any obvious differences. They both contain more hardcoded modifications than I'm comfortable with, and there is one obvious difference which is that the $wmgLBFactoryConfigCallback version starts from an empty $lbFactoryConf = [] instead of extending the base array from wmf-config/db-production.php. However, I don't see how that would result in DEFAULT being set or not in the groupLoadsBySection or sectionLoads keys.

After ruling out a bunch of other things, I decided to stare at /libs/rdbms/LBFactoryMulti.php and its reconfigure() method for a while:

	public function reconfigure( array $conf ): void {
		// …
		foreach ( $this->mainLBs as $lb ) {
			$groupLoads = $conf['groupLoadsBySection'][$lb->getClusterName()];

This is where the error happens. DEFAULT is absent here, but we presume it is present during the "normal" way of configuring during request start up. So first, where does the "normal" access happpen?

The main way that this config is consumed, which is where it will also be consumed from after reconfigure() succeeds, is in newMainLB where we read $this->groupLoadsBySection[$section] and in particular, there is a strict check that not only checks this but also one of the subkeys:

		if ( !isset( $this->groupLoadsBySection[$section][ILoadBalancer::GROUP_GENERIC] ) ) {
			throw new UnexpectedValueException( "Section '$section' has no hosts defined." );
		}

That's pretty strict. So, how come it exists when we read db config from Etcd the "normal" way, but then it is absent when we read it from reconfigure() ? I don't know, but let's trace the life of $this->groupLoadsBySection to its eventual wmf-config source. First, where does it get assigned? It's normally assigned in the constructor:

	public function __construct( array $conf ) {
		// …
		$this->groupLoadsBySection = $conf['groupLoadsBySection'];
		foreach ( $conf['sectionLoads'] as $section => $loadsByServerName ) {
			$this->groupLoadsBySection[$section][ILoadBalancer::GROUP_GENERIC] = $loadsByServerName;
		}

This doesn't appear to be magically creating any extra array keys that aren't in the input.

But! The constructor does mutate groupLoadsBySection. It adds a subkey under section for "generic" with the equivalent sectionLoads data. And that implicitly also does something else. It implicitly creates the $section if it didn't exist yet.

So, given the following hypothetical input:

[
  'sectionLoads' => [
    'foo' => [ 'db01', 'db02' ],
    'bar' => [ 'db03', 'db02' ],
  ],
  'groupLoadsBySection' => [
    'foo' => [
      'a' => [ 'db04' ],
    ],
  ]
];

Note that groupLoadsBySection lacks bar as key. The constructor logic would, I believe, turn it into this:

'groupLoadsBySection' => [
  'foo' => [
    'generic' => [ 'db01', 'db02' ],
    'a' => [ 'db04' ],
  ],
  'bar' => [
    'generic' => [ 'db03', 'db02' ],
  ],
]

In LBFactoryMulti::reconfigure, we do something similar but not identical.

# LBFactoryMulti::__construct
		$this->groupLoadsBySection = $conf['groupLoadsBySection'];
		foreach ( $conf['sectionLoads'] as $section => $loadsByServerName ) {
			$this->groupLoadsBySection[$section][ILoadBalancer::GROUP_GENERIC] = $loadsByServerName;
		}

# LBFactoryMulti::reconfigure
		foreach ( $this->mainLBs as $lb ) {
			$groupLoads = $conf['groupLoadsBySection'][$lb->getClusterName()];
			$groupLoads[ILoadBalancer::GROUP_GENERIC] = $conf['sectionLoads'][$lb->getClusterName()] ?? [];

In the constructor, we don't access any specific key in groupLoadsBySection, instead it merely adds sectionLoads to it.

In reconfigure, we first read a specific cluster key (thus assuming it exists) and then add sectionLoads to it.

But! The constructor does mutate groupLoadsBySection. It adds a subkey under section for "generic" with the equivalent sectionLoads data. And that implicitly also does something else. It implicitly creates the $section if it didn't exist yet.
[…]
In reconfigure, we first read a specific cluster key (thus assuming it exists) and then add sectionLoads to it.

So.... that leaves us with the question: Is this what is happening in production? And if so, how is that happening?

The answer is yes, the data we get from Etcd is missing DEFAULT in some cases. When I started the above analysis, I looked at https://noc.wikimedia.org/dbconfig/eqiad.json and there the DEFAULT key is clearly set. And that makes sense, in so far that when we look at Logstash today, the error in the task description is not happening today.

It happened several times in recent months but only in large but short bursts at seemingly random times. The most recent time was from Friday 2023-09-08 at 21:08 UTC until 2023-09-09 at around 03:00 UTC.

Once a time is known, we can look at the SAL for sometihng that may be happening in production, such as deployments, service switches, hardware changes, data center maintenance, etc. These messages are logged #wikimedia-operations on IRC using !log but can be retreived later via https://wikitech.wikimedia.org/wiki/Server_Admin_Log, with an easier query and filter interface at https://sal.toolforge.org

Looking at https://sal.toolforge.org/production?p=0&q=dbctl&d=2023-09-09 we see two events that correlate well with out timestamps and appear very relevant:

Server Admin Log:

• 2023-09-08 21:08: dbctl commit (dc=all): 'Depooling db1166 (T343198)', diff saved to https://phabricator.wikimedia.org/P52345 and previous config saved to /var/cache/conftool/dbconfig/20230908-210844-arnaudb.json
• 2023-09-09 03:24: dbctl commit (dc=all): 'Repooling after maintenance db1166 (T343198)', diff saved to https://phabricator.wikimedia.org/P52346 and previous config saved to /var/cache/conftool/dbconfig/20230909-032407-arnaudb.json

We see that this temporarily changed the Etcd database config data for a few hours during maintenance on a particular server:

Now from this diff two things stand out:

1. It seems that for the "DEFAULT" section, we have only 1 single host used for any of the group overrides. This means that if this host is depooled, the config naturally becomes empty. This should be fine from the MediaWiki application perspective, because these are merely override hints. The main configuration where we specify the master and replica databases for each section is sectionLoads. It's totally fine to have no group overrides. Although in practice we almost always have not just 1 but more than 1, so it is quite rare for a depool to result in keys being removed instead of merely the array shrinking in-place.
2. It seems to be replacing eqiad/groupLoadsBySection/DEFAULT with an empty JSON object. If true, then this would not explain our production error, because that would mean the groupLoadsBySection['DEFAULT'] top-level key still exists.

I suspect this diff is a lie, and that one of two things is happening:

• dbctl explicitly deletes the key, but the human-readable diff maker is hallucinating an empty object when making the diff.
• Or, dbctl doesn't mean for the key to be deleted, but when conftool or etcd serializes the data structure in request to fetching groupLoadsBySection it may be omitting seemingly empty values and perhaps treating empty object as something to leave out.

But, regardless of why, before we speculate on that, let's first confirm and see for ourselves that there is in fact a missing key and thus that the diff is in fact a lie. I asked @Ladsgroup whether it would be safe to depool this server again, so that we can see what happens.

In T346365#9188734, @Stashbot wrote:

Mentioned in SAL (#wikimedia-operations) [2023-09-21T17:56:34Z] <ladsgroup@cumin1001> dbctl commit (dc=all): 'Depool db1166 (T346365)', diff saved to https://phabricator.wikimedia.org/P52560

Shortly after this, viewing https://noc.wikimedia.org/dbconfig/eqiad.json indeed showed that groupLoadsBySection was in fact missing the key. Yay! The <s>cake</s> diff is a lie!

To confirm the end-to-end behaviour as well, I also used eval.php to reproduce the error:

krinkle at mwmaint1002.eqiad.wmnet in ~
$ mwscript eval.php aawiki -d 2
> MediaWiki\MediaWikiServices::getInstance()->getDBLoadBalancerFactory()->autoReconfigure();

> echo 'Amir depooled the host now';
Amir depooled the host now

> MediaWiki\MediaWikiServices::getInstance()->getDBLoadBalancerFactory()->autoReconfigure();

[error] [error] [d9ca505fb0cfa1afe7406f45] [no req]   PHP Notice: Undefined index: DEFAULT
#0 /srv/mediawiki/php-1.41.0-wmf.26/includes/libs/rdbms/lbfactory/LBFactoryMulti.php(373): MWExceptionHandler::handleError(integer, string, string, integer, array)
#1 /srv/mediawiki/php-1.41.0-wmf.26/includes/libs/rdbms/lbfactory/LBFactory.php(187): Wikimedia\Rdbms\LBFactoryMulti->reconfigure(array)
#2 /srv/mediawiki/php-1.41.0-wmf.26/maintenance/eval.php(126) : eval()'d code(1): Wikimedia\Rdbms\LBFactory->autoReconfigure()
#3 /srv/mediawiki/php-1.41.0-wmf.26/maintenance/eval.php(126): eval()
#4 /srv/mediawiki/php-1.41.0-wmf.26/maintenance/includes/MaintenanceRunner.php(685): MWEval->execute()
#5 /srv/mediawiki/php-1.41.0-wmf.26/maintenance/run.php(51): MediaWiki\Maintenance\MaintenanceRunner->run()
#6 /srv/mediawiki/multiversion/MWScript.php(159): require_once(string)
#7 {main}

Change 959849 had a related patch set uploaded (by Krinkle; author: Krinkle):

[mediawiki/core@master] rdbms: Fix "Undefined index: DEFAULT" in LBFactoryMulti::reconfigure

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

Change 959849 merged by jenkins-bot:

[mediawiki/core@master] rdbms: Fix "Undefined index: DEFAULT" in LBFactoryMulti::reconfigure

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