[date: 2018-03-17 02:16] [visits: 14]

邮件服务器之乌龙

之前帮助处理过一次邮件服务器问题,时隔一个多月,业务部门又找上门,称配置转发的邮箱收到了邮件,但登录到原始邮箱查看不到邮件,本文记录这次问题的解决过程。

事情由来

开完会从办公室出来,已经到了下班点,大部分同事都已离开办公室,唯有IT小哥在座位上用一脸求助的表情看着我。过去一问,原来是收到某业务部门的邮件,称配置转发的邮箱收到了邮件,但登录到原始邮箱查看不到邮件。

邮件中附带一张已发邮件截图,还有吐槽:“上个月才出了问题,这次怎么又出问题,邮件服务器这么不稳定,技术部当斩~”,吓得我赶紧去上了个厕所,然后回到电脑面前寻找故障原因。

初步排查

从业务部门的邮件中得到的信息:收件人、发件人、时间,赶紧上服务器查看日志,通过收件人过滤,得到日志信息:

Mar 15 22:33:12 mail amavis[8019]: (08019-17) Passed CLEAN {RelayedInternal}, MYUSERS LOCAL [205.217.6.15]:51605 [205.217.6.15] <from@gmail.com> -> <to@gmail.com>, Queue-ID: C5E0680F75, Message-ID: <CE62CD047F314E60BA148E1F09B28F24@emt.hobsons.local>, mail_id: fPNzu-G0sYdr, Hits: -2.299, size: 17403, queued_as: D128E80F82, dkim_sd=key3:applyyourself.hobsons.gmail.com, 10586 ms
Mar 15 22:33:12 mail postfix/smtp[10461]: C5E0680F75: to=<to@gmail.com>, relay=127.0.0.1[127.0.0.1]:10024, delay=11, delays=0.48/0.01/0/11, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as D128E80F82)
Mar 15 22:33:12 mail postfix/pipe[10467]: D128E80F82: to=<to@gmail.com>, relay=dovecot, delay=0.06, delays=0/0.01/0/0.05, dsn=2.0.0, status=sent (delivered via dovecot service)

收发件人信息做了替换: ->

虽然对邮件服务器这堆软件不熟悉,但从上面的日志中没有明显察觉到错误,反倒是感觉一切正常,对业务部门的邮件描述产生了轻微怀疑,是不是误报。

二次确认

用日志中的关键词,在Google上搜索了一番,依旧无法确定其含义是邮件接收成功。由于怕业务部门误报,让IT小哥去问邮箱密码,然后登上去查看收件箱。

同时因上次的经验,知道收件箱的邮件是以文件形式存储在本地,开始从数据库中找到该邮箱对应的收件箱目录,并且最终找到收件箱目录,主要包含两个:

服务器已接收但还未被客户端接收过的邮件,即服务器接收到了,但没有用客户查看过

客户端接收过的邮件,打开客户端,看到了收件箱列表即算接收过邮件

随后,在new目录中,找到了那封故障邮件,竟然邮件已经在收件箱,怎么会查看不到呢?轻微奔溃,难道真的是业务部门误报?

进展

在这个过程中,IT小哥问到了密码并且登录了邮箱,里面有30几封邮件,但并没有那封故障邮件,而且服务器上该用户的收件箱中只有12封邮件。

显而易见,通过客户端看到的邮件,并不是服务器上收件箱中的邮件。

至此,已经有点不知所措,病急乱投医,随后用自己邮箱往故障邮箱中发了一封邮件,结果在客户端中依旧看不到该邮件,服务器的收件箱中却存在。

在一脸郁闷中,又用自己邮箱发给另外的一个邮箱,结果一切正常,客户端看到的收件箱和服务器的完全相同。

经过这两个实验,猜测可能是邮箱之间有差异?某些邮箱配置了其他收件箱?但经过半个多小时的Google搜索、数据库查询、以及文件搜索,没发现任何存在其他收件箱的线索。

离奇现象

经过上面的过程,已经觉得故障很离奇了,但怎么也想不到发生了更离奇的现象。

之前都是IT小哥登录的客户端,在我寻找故障原因的同时,IT小哥测试了一次收发件,结果均正常。觉得有些诧异,想着自己测试一次,让他把密码发我,然后在自己电脑上登录邮箱。

登录之后,心态奔溃,因为看到的邮件就是服务器上收件箱中的内容,13封邮件,包含自己发的那封,但IT小哥电脑看到的就是另外的35封邮件...

明明登录的是两个相同的账号,收件箱中的内容竟然不一样?到这一步,不知道有没有读者结合文章标题猜出问题原因,现在自己回过头看这些现象,感觉原因已非常明显,但在当时那种全身专注找技术问题的状态下,硬是没意识到原因所在。

胡思乱想

在见识了这种离奇现象后,脑子已经不够用,胡思乱想:

猜测是浏览器原因时,立马在电脑上打开Safari,登录一看,OMG~,真的与Chrome中收件箱的内容完全不一样...

接着就开始兴奋,因为到了熟悉领域,而且感觉自己离真相只有一步之遥。打开Charles,两个浏览器分别抓包,然后对比,发现除了cookie中sessionId有差别外,其他因素对结果都没影响。

兴奋状态下,思考的很快,觉得是因为浏览器不同,导致登录后,后台对应的收件箱不一样,接着用Charles抓登录请求。

揭示真相

通过对比登录请求信息,果然找到了区别,Safari中用户名少了个0,比如Chrome中是xxxyyyzzz022692@gmail.com,Safari中是xxxyyyzzz22692@gmail.com。果真是因为浏览器差异导致登录账号不一样,猜测是前端代码BUG导致在Safari中补零出错,所以出现用户名不一样。

在这一会,自己兴奋异常,觉得自己的猜测应该很接近真相了,接着准备去证明。

IT小哥这时候说:“你两个浏览器显示的用户名不一样,是不是登错了账号”。

说好的有质量的BUG呢?怎么就变成了搞错账号,我这两个小时又是在做无用功咯?一脸失落的去翻聊天记录,最后真相是:

  1. 业务部门发邮件报故障的图里面,收件人是xxxyyyzzz022692@gmail.com,IT小哥把图片中的邮箱发在故障排查群中
  2. IT小哥找业务部门要邮箱密码,业务部门给了邮箱xxxyyyzzz22692@gmail.com与密码
  3. 在我专心寻找邮箱xxxyyyzzz022692@gmail.com的故障问题时,IT小哥登录了邮箱xxxyyyzzz22692@gmail.com,并且向我说明了收件箱情况
  4. 我找IT小哥要密码时,他私聊发给我的是邮箱xxxyyyzzz22692@gmail.com与密码,但由于我在Chrome中早就输入了用户名xxxyyyzzz022692@gmail.com,只从他消息中Copy密码并成功登录
  5. 用Safari登录时,我从IT小哥的聊天记录中同时Copy了用户名和密码

本次乌龙的核心流程就是上述5步,整个过程中,自己始终在寻找A邮箱的收件箱故障原因,而得到的却是B邮箱的收件箱反馈,并且邮箱密码一样,自己登录时也没有发现邮箱不同,始终认为这是一个技术问题,哪怕不合理,也是因为自己的无知导致不能合理解释。

总结

实际上这种类似“乌龙”,具体情况虽记不得,但职业生涯中遇到过好些次。想必作为程序员的大家或多或少都有过类似经历:“一个非常棘手的问题,一步一步排查,到最后发现是一个很小的失误导致,少一个括号、分号或者是大小写错误、变量覆盖等”。

这类问题的解决能力,需要靠经验积累,以及异常清晰和冷静的头脑,或者养成良好习惯去尽力避免该类问题。当有一些经验之后,每次遇到此类问题,定位的过程中自己潜意识就已经能意识到最终问题原因可能是因为一个极小的失误导致了看似荒诞的错误。虽然有这种潜意识,往往也难以脱离当时的情景限制,就如同上述案例,一个有经验的旁观者,也许不费吹灰之力就能找到问题原因,但作为当局者的自己,真是陷入那种困境之中不知所措。

这次故障定位,没有什么明显收获,但解决每一个问题的过程本身是一种经验,一种积累,帮助自己成为更厉害的程序员,加油,与君共勉。