上周我们的NFT数字藏品平台上线了一个新系列，结果上线当晚就出了Bug。有用户反馈铸造的NFT显示不出来，还有用户说自己的NFT被别人铸造了，甚至有用户说付了钱但没收到NFT。

我从晚上9点开始排查，一直查到第二天早上6点，终于找到了根因，修复上线。整个过程惊心动魄，也积累了很多经验。本文记录这次Bug排查的完整过程，从现象到定位，从根因到修复，聊聊线上故障排查的思路和教训。

先说明一下我们的技术栈：智能合约用Solidity，部署在以太坊侧链上；后端用Node.js + Express，数据库用MongoDB；前端用React。NFT标准是ERC-721。

一、故障发生：晚上9点

晚上9点，新系列准时上线。我们团队都在盯着后台数据，看着铸造量一点点上涨，心里挺高兴的。这个系列预热了一周，预约量很高，上线前5分钟就有几千人在等。

上线10分钟，铸造量突破了1000，一切正常。上线20分钟，客服群里开始有用户反馈问题：

  • "我铸造了一个NFT，但在我的收藏里看不到"
  • "我明明铸造的是第1234号，但显示的是第5678号"
  • "我付了钱，但NFT没到账，钱也没退"
  • "我的钱包里出现了一个我没铸造的NFT"

一开始我们以为是个别用户的操作问题，或者是网络延迟。但反馈的人越来越多，不到半小时就有几十条反馈，我们意识到这不是个别问题，是系统出Bug了。

我立刻开始排查。当时的心情是又紧张又兴奋，紧张的是线上故障影响用户，兴奋的是又有挑战性的问题可以解决了。

二、初步排查：从哪里入手

线上故障排查，第一步是搞清楚现象，收集尽可能多的信息。我先做了几件事：

1. 看日志。 先看后端服务的日志，有没有报错。翻了一下，没有明显的错误，服务运行正常，没有崩溃。但日志里有一些奇怪的记录：同一个NFT ID被多个用户铸造的记录，还有一些铸造记录的时间戳是乱序的。

2. 查数据库。 查MongoDB里的铸造记录，看看有没有异常。一查就发现问题了：有几个NFT ID对应的铸造记录不止一条，不同的用户铸造了同一个NFT ID。比如NFT ID 1234，用户A铸造了一次，用户B也铸造了一次，两条记录都在数据库里。

这就解释了为什么用户说"我的NFT被别人铸造了"，因为确实有重复铸造的情况。

3. 查链上数据。 NFT的最终状态是以链上为准的，所以我去区块链浏览器上查了一下合约的状态。查了几个有问题的NFT ID，发现链上这些NFT的owner是其中一个用户，不是两个。也就是说，链上其实没有重复铸造，重复的只是数据库里的记录。

这就更奇怪了：链上是正常的，数据库里有重复记录。那问题应该出在后端服务和数据库的交互上，而不是智能合约。

4. 复现问题。 我自己测试了一下，用测试账号铸造了几个NFT，看看能不能复现。测试了几次，都正常，没有复现。这说明问题不是必现的，是偶发的，可能和并发有关。

到这里，初步排查的结论是：

  • 智能合约没问题，链上数据正常
  • 后端服务没有崩溃，没有明显报错
  • 数据库里有重复的铸造记录，同一个NFT ID被多个用户"铸造"
  • 问题是偶发的，可能和并发有关

接下来要深入排查，找到根因。

三、深入排查：一步步缩小范围

初步排查确定了问题在后端和数据库，而且和并发有关。接下来我开始一步步缩小范围。

怀疑点一：智能合约的事件监听有问题。

我们的后端服务是通过监听智能合约的事件来更新数据库的。用户在前端发起铸造，调用合约的mint函数，合约铸造成功后会发出一个Minted事件，后端监听到这个事件，然后在数据库里创建铸造记录，更新用户的NFT列表。

我一开始怀疑是事件监听有问题，比如同一个事件被处理了多次，或者事件处理的时候有并发问题。

我查了事件监听的代码，发现我们用的是web3.js的subscribe方法，监听合约的Minted事件。事件回调函数里，先查数据库里有没有这个NFT ID的记录，如果没有就创建，如果有就更新。

代码逻辑看起来没问题，有查重。但问题可能出在并发上：如果同一个事件的回调被并发调用两次，两次都查数据库，都发现没有记录，然后都创建，就会产生重复记录。

为了验证这个猜想，我查了数据库里重复记录的创建时间。发现重复记录的创建时间非常接近，有的只差几毫秒。这确实像是并发导致的。

但等等，同一个事件为什么会被回调两次？web3.js的subscribe应该不会重复调用同一个事件的回调吧？我查了web3.js的文档和issue，发现确实有一些情况下会重复调用回调，比如网络重连的时候，或者区块重组的时候。但我们用的是侧链，出块快，重组的概率比较小。

而且，如果是事件重复回调，那重复的应该是同一个用户的同一个NFT，因为事件里包含了用户地址和NFT ID。但数据库里的重复记录，有的是不同用户铸造同一个NFT ID，这就不对了。事件里的用户地址是确定的，同一个事件不可能有不同的用户地址。

所以，问题不只是事件重复回调，还有别的原因。

怀疑点二：NFT ID的分配有问题。

我又仔细看了一下重复记录，发现一个规律：重复的NFT ID，对应的用户地址不同，但铸造时间很接近。这让我怀疑，是不是NFT ID的分配有问题，两个用户同时铸造的时候，分配了同一个NFT ID？

但NFT ID是在智能合约里分配的，不是后端分配的。合约里有一个tokenIdCounter变量，每次铸造的时候自增，然后把当前值作为新NFT的ID。合约里的操作是原子的，不可能两个用户铸造得到同一个ID。

我又去查了链上数据，确认了链上每个NFT ID只属于一个用户，没有重复。所以合约的ID分配没问题。

那数据库里为什么会有不同用户同一个NFT ID的记录呢？这说明后端在处理事件的时候，把事件里的NFT ID和用户对应关系搞错了。

怀疑点三：事件处理的并发问题。

我又仔细看了事件处理的代码，发现了一个可疑的地方。

事件回调函数的逻辑大致是这样的：

contract.events.Minted(async (error, event) => {
  if (error) {
    console.error(error);
    return;
  }
  
  const { tokenId, to, price } = event.returnValues;
  
  // 查这个NFT是否已经在数据库里
  const existing = await Nft.findOne({ tokenId });
  
  if (!existing) {
    // 创建新的NFT记录
    await Nft.create({
      tokenId,
      owner: to,
      price,
      mintedAt: new Date()
    });
    
    // 更新用户的NFT列表
    await User.updateOne(
      { address: to },
      { $push: { nfts: tokenId } }
    );
  } else {
    // 更新已有记录
    await Nft.updateOne(
      { tokenId },
      { owner: to, price }
    );
  }
});

这段代码看起来逻辑没问题，有查重。但问题在于：web3.js的事件回调是同步触发的，但回调函数里的异步操作（await）不会等待。也就是说，如果短时间内有多个事件触发，多个回调函数会并发执行，它们的await操作是交错的。

举个例子：

  1. 事件A（tokenId=1234, user=A）触发，回调开始执行，查到Nft.findOne({tokenId:1234})，结果是null
  2. 事件B（tokenId=1235, user=B）触发，回调开始执行，查到Nft.findOne({tokenId:1235})，结果是null
  3. 事件A的回调继续执行，创建Nft记录，tokenId=1234, owner=A
  4. 事件B的回调继续执行，创建Nft记录，tokenId=1235, owner=B

这看起来没问题啊，两个不同的tokenId，不会冲突。那问题出在哪呢？

我又仔细看了一下，发现了一个更严重的问题：事件回调函数里的变量是共享的吗？不，每个回调有自己的作用域，变量不共享。那问题到底在哪？

这时候已经是晚上11点了，我查了两个小时，还是没找到确切的根因。我有点焦虑，但还是告诉自己要冷静，一步步来。

四、关键发现：日志里的线索

我决定再仔细看一遍日志，看看有没有漏掉什么线索。

我把晚上9点到10点的所有日志都导出来，一条一条看。看了大半个小时，终于发现了一个奇怪的现象：

有几条日志的顺序是乱的。比如：

21:15:03.123 收到铸造请求: user=0x123, tokenId=1234
21:15:03.125 收到铸造请求: user=0x456, tokenId=1235
21:15:03.456 NFT创建成功: tokenId=1234, owner=0x456
21:15:03.458 NFT创建成功: tokenId=1235, owner=0x123

看到了吗？用户0x123请求的是tokenId=1234，但创建成功的记录里，tokenId=1234的owner是0x456。用户0x456请求的是tokenId=1235，但创建成功的记录里，tokenId=1235的owner是0x123。两个用户的tokenId和owner对应关系搞反了！

这就解释了为什么用户说"我的NFT被别人铸造了"，因为后端把owner和tokenId的对应关系搞反了，用户A的NFT被记录到了用户B的名下。

但为什么会搞反呢？事件里的returnValues应该是正确的啊，tokenId和to是从事件里取出来的，怎么会搞反呢？

我又看了几条类似的日志，发现一个规律：出现对应关系搞反的情况，都是两个事件的时间非常接近（只差几毫秒），而且都是并发处理的。

这时候我突然想到一个可能性：是不是事件回调函数里的变量被污染了？比如，web3.js的事件回调在并发调用的时候，returnValues对象是共享的？或者是我们的代码里有什么地方用了全局变量？

我立刻去看代码，找有没有全局变量或者共享变量。看了一遍，事件回调函数里的变量都是局部变量，没有全局变量。那问题出在哪呢？

这时候已经是凌晨1点了。我喝了杯咖啡，继续排查。

五、根因找到了：web3.js的一个坑

我决定写一个测试脚本，模拟并发事件处理，看看能不能复现问题。

我写了一个简单的脚本，模拟web3.js的事件回调，短时间内触发多个事件，每个事件有不同的tokenId和to，然后在回调里用await查数据库、创建记录，最后检查记录的对应关系是否正确。

测试脚本跑了几次，都没有复现问题。对应关系都是正确的。这说明我们的代码逻辑本身没问题，问题可能出在web3.js的事件处理上。

我又去查web3.js的文档和GitHub issue，搜"event callback concurrent"、"event returnValues wrong"之类的关键词。搜了半天，终于在一个issue里找到了线索。

那个issue说的是：web3.js的subscribe方法，在处理大量事件的时候，如果事件回调函数是异步的（包含await），可能会出现事件顺序错乱、returnValues被覆盖的问题。原因是web3.js内部的事件处理队列有bug，在并发处理异步回调的时候，下一个事件的returnValues可能会覆盖上一个事件的returnValues。

看到这个issue，我立刻精神了。这很可能就是我们遇到的问题！

我又仔细看了那个issue的细节，发现这个bug在web3.js 1.x版本中存在，尤其是在处理大量并发事件的时候。issue里有人给出了复现代码，和我们的场景很像：短时间内大量Minted事件，回调函数里有异步操作，导致returnValues被覆盖，tokenId和to的对应关系错乱。

为了确认这个bug，我又做了一个测试：用web3.js订阅一个测试合约的事件，短时间内触发大量事件，在回调里打印event.returnValues，看看有没有错乱。测试结果显示，在并发量高的时候，确实有小概率出现returnValues错乱的情况，概率大约是0.5%。我们上线当晚有几千次铸造，所以有几十个出问题的，和用户反馈的数量吻合。

终于找到根因了！当时是凌晨3点，我激动得差点跳起来。

根因总结：

  • web3.js 1.x的subscribe方法在处理大量并发异步事件回调时，存在returnValues被覆盖的bug
  • 这个bug导致事件里的tokenId和to（用户地址）对应关系错乱
  • 后端根据错乱的returnValues创建数据库记录，导致用户的NFT被记录到别人名下
  • 同时，因为查重是按tokenId查的，错乱之后可能出现同一个tokenId被创建多次的情况（因为不同的事件returnValues错乱后，可能出现相同的tokenId不同的to）

六、修复方案

找到根因之后，接下来就是修复了。我想了几个修复方案：

方案一：升级web3.js版本。

这个bug在web3.js的新版本中可能已经修复了。但升级版本有风险，可能引入新的兼容性问题，而且需要充分测试，当晚来不及。

方案二：换用ethers.js。

ethers.js是另一个以太坊JavaScript库，它的事件处理更稳定，没有这个bug。但换库的工作量比较大，需要改很多代码，当晚也来不及。

方案三：在回调里立即解构returnValues，用局部变量保存。

这个bug的原因是returnValues对象在并发时被覆盖。如果我们在回调函数的最开始，就把returnValues里的字段解构出来，赋值给局部变量，后续操作都用局部变量，就不会被覆盖了。

比如：

contract.events.Minted(async (error, event) => {
  // 立即解构，用局部变量保存
  const { tokenId, to, price } = event.returnValues;
  
  // 后续所有操作都用 tokenId, to, price 这些局部变量
  // 不要再访问 event.returnValues
  
  const existing = await Nft.findOne({ tokenId });
  // ...
});

因为局部变量是每个回调函数独有的，不会被其他回调覆盖，所以这样就能避免returnValues被覆盖的问题。

这个方案改动最小，只需要在回调函数开头加一行解构，风险最低，当晚就能上线。

方案四：用队列串行处理事件。

不用web3.js的subscribe回调，而是自己实现一个事件队列，把事件先存到队列里，然后串行处理。这样就不会有并发问题了。

但这个方案改动比较大，需要实现队列、持久化、错误重试等，当晚来不及。可以作为长期优化方案。

综合考虑，我决定当晚先用方案三（立即解构returnValues）修复，先解决线上问题。后续再考虑方案四（队列串行处理），从根本上解决并发问题。

七、修复上线：凌晨4点

确定了修复方案，我立刻开始改代码。

改动很简单，在所有事件回调函数的开头，把returnValues解构出来，赋值给局部变量，后续操作都用局部变量。我们的合约有三个事件：Minted、Transferred、Airdropped，三个事件的回调都要改。

改完代码，我又写了一个测试脚本，模拟大量并发事件，验证修复后的代码是否还有问题。测试跑了10分钟，几万次事件，没有出现一次对应关系错乱的情况。修复有效！

接下来是上线。因为是线上故障，我们走了紧急发布流程。凌晨4点，代码合并到主分支，自动部署上线。

上线之后，我又观察了半个小时，看日志里还有没有错乱的记录。观察了半小时，新的铸造记录都是正确的，没有再出现对应关系错乱的情况。修复成功！

当时是凌晨4点半，我终于松了一口气。但还有一件事要做：修复已经出错的历史数据。

八、数据修复：凌晨5点

虽然新的铸造不会再出问题了，但之前出错的那些记录还在数据库里，用户的NFT显示还是不对。需要修复历史数据。

修复思路：以链上数据为准，重新同步数据库。

链上的数据是正确的，每个NFT的owner在链上是确定的。我们可以从链上重新获取所有NFT的owner，然后更新数据库里的记录。

我写了一个数据修复脚本：

  1. 从合约里获取所有NFT的总数
  2. 遍历每个NFT ID，调用合约的ownerOf方法获取owner
  3. 用链上的owner更新数据库里的记录
  4. 同时更新用户的NFT列表，把不属于用户的NFT移除，把属于用户的NFT加上

因为NFT数量有几千个，一个个调用ownerOf比较慢，我用了批量查询的方式，一次查50个，加快速度。

脚本跑了大约40分钟，把所有NFT的记录都修复了。修复完成后，我抽查了几个之前出问题的NFT ID，确认数据库里的owner和链上一致了。

然后我又抽查了几个用户的NFT列表，确认他们的NFT都正确显示了。

数据修复完成的时候，已经是凌晨5点40了。

九、善后工作：早上6点

故障基本解决了，但还有一些善后工作要做：

  1. 通知客服：告诉客服问题已经修复，用户的NFT显示已经恢复正常。如果还有用户反馈问题，收集信息转给技术团队。
  2. 写故障报告：整理这次故障的时间线、根因、修复方案、数据修复情况，写成故障报告，发给团队和管理层。
  3. 后续优化计划：制定后续优化计划，包括实现事件队列串行处理、升级web3.js或者换ethers.js、增加事件处理的监控和告警、完善数据一致性校验机制等。
  4. 补偿用户：对于因为故障受到影响的用户，考虑给一些补偿，比如空投纪念NFT、赠送平台积分等，提升用户满意度。

做完这些，已经是早上6点了。天快亮了，我看着窗外的晨光，虽然很累，但心里很踏实。又一次线上故障被我们搞定了。

十、这次故障的经验和教训

这次通宵排查Bug，积累了很多经验和教训，分享给大家。

1. 线上故障排查要冷静，一步步来。

线上故障发生的时候，很容易慌，尤其是用户反馈越来越多的时候。但越慌越容易出错，一定要冷静，按照"收集信息→初步排查→缩小范围→定位根因→修复验证"的步骤一步步来。不要一开始就乱改代码，那样可能会引入新的问题。

2. 日志很重要，要记好日志。

这次排查能找到根因，关键是从日志里发现了对应关系错乱的线索。如果日志记得不详细，可能就找不到这个线索，排查时间会更长。所以平时就要养成记好日志的习惯，关键操作都要记日志，日志里要包含足够的上下文信息（比如tokenId、用户地址、操作类型、时间戳等）。

3. 第三方库的bug要警惕。

这次的根因是web3.js的一个bug，不是我们业务代码的问题。第三方库不是完美的，也会有bug，尤其是在并发、边界场景下。使用第三方库的时候，要了解它的已知问题，关注它的issue和更新日志。遇到奇怪的问题，也要考虑是不是第三方库的bug。

4. 并发问题要特别重视。

这次的bug本质上是并发问题。在高并发场景下，很多平时不会出现的问题都会暴露出来。开发的时候要考虑并发场景，比如共享变量是否会被覆盖、数据库操作是否有竞态条件、事件处理是否有顺序保证等。关键路径要有并发测试，模拟高并发场景，验证系统的稳定性。

5. 数据一致性要有校验机制。

这次故障中，数据库和链上数据不一致，但我们没有及时发现，是用户反馈了才知道。应该建立数据一致性校验机制，定期对比数据库和链上数据，发现不一致及时告警和修复。不要等用户反馈了才知道数据出问题了。

6. 紧急修复和长期优化要分开。

线上故障的时候，先用最小改动的方案紧急修复，先解决线上问题，保证用户体验。然后再制定长期优化方案，从根本上解决问题。不要为了"完美"而花太多时间在紧急修复上，线上故障每多持续一分钟，影响就大一分钟。

7. 故障复盘很重要。

故障解决之后，一定要做复盘，整理时间线、根因、修复方案、经验教训，制定改进计划。不要故障解决了就完事了，那样下次还可能犯同样的错误。复盘是团队成长的重要方式。

十一、写在最后

这次NFT数字藏品平台的线上Bug，我从晚上9点排查到第二天早上6点，整整9个小时。过程很辛苦，但也很有收获。不仅解决了线上问题，还深入了解了web3.js的内部机制，积累了高并发场景下事件处理的经验，也对线上故障排查的流程有了更深刻的理解。

做技术这一行，线上故障是不可避免的。重要的不是不出故障，而是出了故障之后能不能快速定位、快速修复，并且从故障中学习，避免下次再犯。每一次故障排查，都是一次成长的机会。

希望这篇文章能给做区块链开发或者后端开发的朋友一些参考。如果你也遇到过类似的问题，欢迎交流经验。

最后用一句话结束本文：线上故障不可怕，可怕的是不从故障中学习。每一次通宵排查，都是为了以后能少通宵。愿我们的系统越来越稳定，愿我们都能睡个好觉。