2029年选举：一个不可能出现的异常

我原以为我已经写过关于我的Election 2029网站（https://election2029.uk）的第一篇博客文章，但看来我的博客进度比我想象的要落后。因此，这是本系列中一篇有点奇怪的首篇文章，但没关系。在某种程度上，它与选举网站并没有特别相关，除了：a）这是相对现代的C#代码，与我的大多数代码库相比；b）它将解释相关的两个字符串。

我必须强调：当我的代码出现问题时，几乎总是我的错。（我以前在博客中写过这一点。）

但在星期四，我看到了一个无法解释的异常。本文将提供一些背景信息，展示涉及的代码和异常消息，以及我下一步（相当薄弱）的措施。本文的目的有三个：

这是一种谦卑的行为：如果我在诊断棘手问题并对自己感到满意时发帖，那么在遇到难题时也应该同样愿意发帖。
有可能有人会对发生的事情有所洞察，并添加评论。
如果我真的找出问题所在，那么有这篇在原始问题发生时写的文章将会很有帮助。

当我的代码出现问题时，几乎总是我的错。

首先，简要介绍网站如何存储数据。

选举数据

我将在未来的文章中详细介绍网站的整体架构，但就本文而言，你只需要知道：

数据存储在Firestore中
正常的页面请求根本不访问数据库。相反，所有数据都保存在内存中，并偶尔（每个实例原子性地）更新。包含所有数据（以相对“原始”的形式）的类型称为ElectionContext，并且是完全不可变的。
在开发过程中，有一个手动的“重新加载当前数据”页面，在我知道更新了数据库后使用。（我将在另一篇文章中详细解释我的重新加载计划。）
当ElectionContext重新加载时，它会执行一些验证——如果无效，重新加载操作将失败，并继续使用先前加载的数据。（当然，这对于新启动的实例没有帮助。）验证的一部分是检查某些集合是否按预期顺序排列。

上下文中的两个集合是数据提供者和预测集。星期四我添加了一个新的数据提供者（Focaldata）和他们的第一个预测集。

我总是先将数据添加到本地测试环境（使用Firestore和基于文件的版本）、我的暂存环境，最后是生产环境。当我更新ElectionContext时，我会在存储之前验证它，然后从头获取两次，两次都进行验证，然后检查：a）第一次获取的上下文等于我存储的上下文，b）第二次获取的上下文等于第一次获取的上下文。

当我的代码出现问题时，几乎总是我的错。

代码和异常

这是在ElectionContext.Validate()方法中用于检查集合顺序的代码：

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16


void ValidateOrdering<T>(
    IEnumerable<T> source,
    Func<T, string> selector,
    [CallerArgumentExpression(nameof(source))] string? message = null)
{
    foreach (var (current, next) in source.Zip(source.Skip(1)))
    {
        string currentText = selector(current);
        string nextText = selector(next);
        if (StringComparer.Ordinal.Compare(currentText, nextText) >= 0)
        {
            throw new InvalidOperationException(
                $"Incorrect ordering for {message}: {currentText} should occur before {nextText}");
        }
    }
}

特别是对于预测集：

1

ValidateOrdering(PredictionSets, ps => ps.Id);

PredictionSets属性是一个ImmutableList，而PredictionSet是一个记录：

1

public sealed record PredictionSet(string Id, /* 许多其他属性 */)

所以基本上，代码是检查所有预测集的ID是否按顺序排列，使用序数字符串比较进行排序。（看到异常后，我的最初想法是涉及某种奇怪的文化，我正在进行特定于文化的排序检查——但不对，它是序数的。）

当我推送新数据时，测试和暂存环境都正常。当我在生产环境中点击重新加载页面时，重新加载失败，日志中出现此异常：

1
2
3


System.InvalidOperationException:
  Incorrect ordering for PredictionSets: mic-01 should occur before focaldata-01
  at Election2029.Models.ElectionContext.<Validate>g__ValidateOrdering [...]

在我们更详细地查看异常本身之前，日志显示了对重新加载页面的五个请求：

20:15:38，新数据尚未存储：重新加载页面发现没有新数据，并成功
20:15:45、20:15:49和20:15:57，重新加载操作失败（每次都出现上述异常）
20:26:22，重新加载操作成功

有趣的是，重新加载操作的存储组件会查找新数据，如果没有则返回其缓存版本；上一级的组件执行验证。（此缓存版本不是“服务”上下文——它只是在存储组件中。因此在此期间，网站继续提供先前只有一个预测集的数据。）在这种情况下，日志显示：

20:15:38：没有新数据，因此返回缓存——然后验证成功
20:15:45：加载新数据，然后验证失败
20:15:49：没有新数据，因此返回缓存的上下文，然后验证失败
20:15:57：没有新数据，因此返回缓存的上下文，然后验证失败
20:26:22：没有新数据，因此返回缓存的上下文——然后验证成功

换句话说，三次验证失败的相同数据后来验证成功。日志条目明确表示没有加载任何内容——因此似乎不是存储组件的问题，即数据最初加载不正确，后来正确加载。我说“似乎不是”是因为当我的代码出现问题时，几乎总是我的错。（而且表象可能具有欺骗性。基本上，在我有办法重现问题之前，我对任何推论都持怀疑态度。）

让我们再次查看代码和异常。

我们“知道”/怀疑什么？

在异常中，mic-01和focaldata-01是两个预测集的ID。在生产环境中，这是仅有的两个预测集，并且这些是正确的ID。异常消息暗示在异常发生时，currentText的值是"focaldata-01"，而nextText的值是"mic-01"。这些值是有意义的，因为我原本期望"focaldata-01"排在"mic-01"之前。

换句话说，看起来数据是正确的，但检查是错误的。换句话说，用实际（ apparent）值替换参数后，看起来这个表达式评估为true：

1
2


// 这怎么可能为真？
StringComparer.Ordinal.Compare("focaldata-01", "mic-01") >= 0

为了覆盖一些正常情况，即使它们不容易解释异常：

使用source.Zip(source.Skip(1))可能看起来令人担忧，因为集合可能发生变化，但source是一个ImmutableList。
PredictionSet.Id的类型是string——所以它是不可变的。
PredictionSet本身是不可变的，因此Id不会随时间改变。
最重要的是，currentText和nextText都是循环中的局部变量。

当我的代码出现问题时，几乎总是我的错。但在这种情况下，我真的、真的无法理解这怎么可能。

我剩下两种可能性：

序数字符串比较器有一个错误，使得结果非确定性（别忘了同样的检查在同一台机器上几分钟后通过了）。
JIT编译器有一个错误，意味着参数没有正确评估——要么它们以错误的顺序传递，要么可能第二个参数或两个参数由于某种原因评估为null，但随后在异常的字符串格式化中正确评估。

老实说，这两种情况似乎都不太可能。第二种情况似乎更可能一些，因为我已经知道.NET 9中的一个JIT编译器问题影响了我的Google Cloud客户端库工作中的一些客户。但我不够理解链接的问题来判断它是否能解释这个异常。

下一步是什么？

我无法在任何环境中重现这个问题。我能想到的唯一改进诊断的方法是记录每个字符串的长度作为异常的一部分，以排除不可打印字符：

1
2


throw new InvalidOperationException(
    $"Incorrect ordering for {message}: {currentText} (length {currentText.Length}) should occur before {nextText} (length {nextText.Length})");

这不多，但这是我目前所有的。

我的猜测是我永远不会知道这里发生了什么。我永远不会再看到这个异常，但也永远无法在“之前”状态重现它以知道它已被修复。所有这些都有些不令人满意——但至少有趣。哦，我仍然坚信当我的代码出现问题时，几乎总是我的错。

更新——已解决！

感谢一位更聪明的同事，这个谜团现在已经解决了。虽然她没有足够的上下文来知道问题实际在哪里，但她能够指出我上面推理出错的地方。