有些 bug 安静得可怕。
它不抛异常,不写错日志,不会在凌晨三点把你叫醒。它只是在一个没人盯着的方法里,把同一件事默默做了两遍。
这件事发生在 keycloak-spi-workbench 项目里。这是一个自定义 Keycloak SPI 提供者集合,其中包含一个只读的旧用户存储联邦模块。它的任务是去查一张现存的 JDBC 表,把里面的用户对接到 Keycloak 里,而不是强行搞一场大爆炸式迁移。
问题出在 LegacyUserStorageProvider 的一个方法里:searchForUserByAttributeStream。
这个方法的逻辑看起来简单得不像有问题。它先调用一次 getUserByUsername 做空值检查,然后再调用一次同一个方法去构建返回的流。如果查到了用户,就返回包含该用户的流;查不到,就返回空流。
两次调用,两次独立的 JDBC 往返。而它背后的 LegacyUserRepository 偏偏故意没有用连接池——每次查询都开一个新的 Connection。这件事在仓库的 README 里有专门说明,是他们有意为之。
结果就是,每一次基于用户名属性的查找操作,数据库承受的负载都是它实际需要的两倍。没有报错,没有结果异常,只是每次调用都在无声地做双份工。
这个 bug 怎么找出来的?靠人眼读代码。没有任何监控工具发出警报,单纯是有人一行行看逻辑时发现了不对劲。修复也直接:把第一次查到的结果存起来,重用一次,加上一个回归测试,确保同样的写法不会再回来。
但这事让人不踏实。这次用眼看到了,下次呢?这种问题能不能不依赖代码审查来发现?
答案是接入异常追踪。
埋点落在 LegacyUserRepository 的三个查询方法里:findOneWhere、search 和 count。它们现在都会在当前 Keycloak 请求追踪的事务之下,开启一个子 span。findOneWhere 的 span 名叫 legacy_db.find_one,search 的叫做 legacy_db.search。而且 search 这个 span 还会记录返回了多少行数据。
这里有一段关键的防御性代码。开启子 span 时,它会先拿当前活跃的追踪 span。如果拿到了,就在它下面创建子 span;如果拿不到,就返回一个 NoOpSpan 实例。这东西什么都不做,保证方法签名一致,但不会产生任何追踪数据。
同样的设计也用在异常捕获上。一旦 SQLException 出现,异常捕获方法会先把它记录下来,然后再包装、重新抛出。这意味着老数据库挂了,不再只是静静躺在一份没人 tail 的 Keycloak 日志里,而是作为一个事件出现在监控控制台上。
如果事情到这里就结束了,这最多算一次还算工整的监控接入。但真正值得记一笔的部分在 init 方法里。
这套 SPI 提供者没有在启动时自动初始化追踪 SDK。它去检查环境变量 SENTRY_DSN。如果没设置这个变量,或是变量值为空,初始化方法根本不会执行。
不执行意味着什么?所有 span 调用都抵达 NoOpSpan 实例,所有异常捕获调用都是空操作。整个监控管线从头到尾不存在。没有 DSN,就没有任何数据会被发到任何地方去。
这是设计上的自觉,不是功能限制。因为这套提供者是给别人安装进他们自己的 Keycloak 实例里用的。开发者不能默认别人愿意把错误追踪账号接进自己的认证服务器,更没有权利在用户不明确授权的情况下,靠一段静默代码把数据往外发。
所以这个入口只有一个开关:环境变量。显式地设了,才意味着同意接入监控;没设,一切恢复为零负担、零外联的本地运行状态。
回到最初那个重复查询的 bug。它很无聊,很常见,常见到你甚至不会觉得它值得写一篇文章。但恰恰是这种无聊问题的隐蔽性,才让监控的有无变得界限分明。一个 SQL 查询被执行了两次,不会让系统瘫掉,但你不知道它在发生。而一旦你有了 span,有了每次 search 返回的行数记录,这种重复就不会再躲在逻辑盲区里。
更值得记住的是,这些 span 本身也需要被设计成不惹事的存在。不依赖外部服务可达性来决定登录操作是否成功;不当默认功能开启;不替用户做决定。
热门跟贴