程序员夏洛克之被踢出去的用户

0

在还没有掌握全部证据之前就下结论会犯严重的错误，会使判断带有偏见。——《血字的研究》

“齐识，路老板又来邮件了。”白娜一脸无耐地说。

“一定没好事吧？”齐识回头看了一眼，手依旧在快速敲着代码，并没有停。

“你刚从泰国回来？”齐识说到。

“你怎么知道？”白娜瞪着眼睛一头雾水。她清明假期去泰国玩这件事，并没有告诉任何同事。

“你脸明显比节前黑了，说明去了热带地区玩。你戴的耳环以前没看到过，说明是假期新买的。耳环上刻着大象……”，齐识停下敲代码的手，回过头，“说明你去了视大象为国宝的泰国。”

“你……牛……，不愧是程序员名侦探……”。

“说吧，又出什么事了？”齐识回到显示器前继续敲代码。

“还是用户被踢出去的那个问题。”

“上次不是已经查清楚了吗？是低版本IE的锅。”

“可是，这次是IE 11……”

“哎——”齐识长叹一声，“好吧，把邮件转给我。”

“已经转给你了。拜托了，我去开会了哈。”

齐识很不情愿地将界面从IDE切换到网页，打开了邮件。这是一封几经转发的邮件，一开始是路老板的用户向路老板抱怨系统用着用着就自动登出了你们这什么烂系统，路老板回复说可能是低版本IE的锅爸爸请考虑升级IE或换其他浏览器。客户说老子TM用的就是最新版IE你是不是在玩老子，于是路老板转发给项目经理白娜说今天必须解决否则炒了你们整个团队。最后白娜转发给齐识，只有三个字母：FYI……

很麻烦。这个问题以前也出现过几次，一直没有找到具体原因。上一次时发现用户用的是IE 8，而当时系统支持的IE最低版本是9。当所有人都焦头烂额束手无策的时候，这位超级英雄背锅侠IE站了出来。果不其然当用户换了其他浏览器后，就再也没有出现过类似问题了。

但这次，背锅侠说这锅老子不背了。

齐识看了看表，上午11点。不知道要为这个问题加班到几点。

他先打开了日志分析工具，按照用户名查询与该用户有关的日志。永远不要相信一个不懂电脑的用户所描述的事实，所有的信息都要再次确认。但这次事实似乎很无情无义无理取闹，这个用户用的确实是IE 11。

通过日志，可以看到这个用户所有的访问记录：他先是登录系统，打开几个页面，然后到了文件管理子系统，找到某个文件夹，上传了一个文件，然后就登出了。如果用户描述属实的话，这次登出请求不是他主动触发的，是系统自动把他踢出去了。

“用着好好的，怎么就被踢出去了呢？”齐识自言自语道。

“怎么了大侦探，愁眉苦脸的。”老夏端着泡了枸杞的保温杯路过。现在是11点半，这杯应该是第三泡。老夏以前也是项目上的大牛，后来不知怎的，去了培训部专门做员工培训了。不过他时不时还是会到研发部这边溜达溜达，从背后窥探一下别人的屏幕，指出代码上的一些问题，然后哈哈一笑扬长而去深藏功与名。

“用户又被自动踢出去了。”齐识说。

“又是那个问题？不是IE的锅吗？”

“看来我们有可能冤枉IE了，这次用户用的是新版本IE，按理说我们的前端是肯定支持的，也在测试环境验证过无数遍了。”

“这就怪了。这几次出问题的用户，是不是都用的IE？”

“是的。”

“那就还是IE的锅。”老夏吸溜了一口枸杞茶，走了。

他看似不经意的一句话，反倒提醒了齐识。他立马继续查询日志，找出几个用不同浏览器的用户，他们的各种操作错落有致，最后的登出请求也并无破绽。只有一些IE用户，他们的登出请求是在上传完文件之后发生的。难道是上传文件的后台接口出了问题？但不同浏览器产生了不同的行为，这现象又 不像是后台的事儿啊。齐识一看表，已经12点半了。得了，先去吃饭吧。

1

……权衡点滴证据，做出不同的假设，把它们进行对比，最后再确定哪几点是重要的、哪些是不真实的…… ——《巴斯克维尔的猎犬》

草草吃完，买了杯咖啡，齐识又坐到了电脑前。像这种线上问题，尤其是本地无法复现的线上问题，是他最喜欢的。定位这些问题的过程，就像是侦探在探案，从最初的案件出发，将看似毫无关联的线索逐一梳理过滤，那最终唯一的真相也会慢慢浮出水面。每到这时，齐识就会感觉像是个超级英雄一样拯救了世界。这样的问题解决得多了，同事们给他起了个外号，叫“程序员侦探”。他倒也不介意别人这么叫他，反倒有点自豪。

但这次用户被踢出的问题，齐识前前后后处理过三次，都无法定位。按照目前系统的实现，用户自动登出可能是因为网站的登录cookie过期且SSO上的登录cookie也过期，这时当某个请求到达后台时，会清空所有与认证有关的cookie并重定向到SSO的登录页面。登录cookie的有效期是20分钟，但用户抱怨的是刚登录不久就被自动踢出，从日志上看也的确如此。所以“登录cookie过期”的不在场证明相当完美。

另外的可能就是缓存挂了。每个请求到达后台时，都会到服务器缓存中取出在用户登录时存储的一个token，将之与请求所携带的cookie中的token比较，如果不相符就自动登出。之所以这样做是考虑用户的安全，将伪造或窃取cookie登录的黑客拒之门外。如果存储或读取缓存失败，自然也会自动登出。齐识以前在读写缓存的地方加了很详细的日志，并没看到任何错误发生。“缓存”作案的可能性也不大。

最后一个嫌犯是心跳请求。网站前端每隔2分钟会自动向后台发一个心跳请求，如果服务器发现本次心跳与上一次心跳间隔时间超过3分钟，就认为用户已处于不活跃状态，自动将其登出。这么做也是为了用户安全，比如将所有网站页面关闭，3分钟后再次打开，将会自动跳转到登录页面。如果心跳请求没有发送成功，下次请求到来时很可能已经超过了3分钟，就会把用户踢出去。心跳请求可以在Web服务器的日志中查到，每次请求都是成功的。所以，“心跳”的嫌疑似乎也撇清了。

就在上一次处理这个问题时，齐识偶然发现请求日志里显示的UserAgent是网站不支持的IE 8。使用系统不支持的浏览器，任何诡异的事情都可能发生。当用户升级了IE或使用了其他浏览器后，问题不再发生了。但是这一次，为什么新版的IE也不行了呢？

现在，齐识的目光集中在了上传文件的后台API上。这是这次发现的新嫌疑人，不，还有IE，可能是团伙作案。现在掌握的最新线索是，用户使用IE，不管什么版本，在上传完文件后，被自动登出。对于IE这种惯犯，不容易找出它的破绽，所以齐识决定先从API下手。

2

在没有事实作为参考以前妄下结论是个很大的错误。主观臆断的人总是为了套用理论而扭曲事实，而不是用理论来解释事实。——《波希米亚丑闻》

两个小时过去了，还是没有任何进展。上传文件的API若无其事地待在那里，一脸蔑视地看着齐识。

“有新的线索吗？”老夏又端着保温壶过来了。现在是下午3点，壶里应该泡上了新茶。老夏喜欢在午饭后泡一壶酽茶。

“今天的普洱味道如何？”齐识问。

“不是普洱，是正山小种。”

“咦？红茶应该是周四泡的啊，今天周三应该是普洱才对。”

“这个嘛，突然就想喝红茶了，呵呵。”老夏说完吐了吐茶沫。“你有不错的洞察力，总是能发现别人不太在意的事情。但有时候，根据那些事实并不能推理出你的结论。有些事情之间的关联可能很偶然，并不具备规律性。”老夏微笑地看着齐识，“现在情况如何？”

“我现在在看上传文件的API。我发现每次用户调用完这个API之后就会被踢出去。”

“哦？有意思，这个API做了什么见不得人的事了吗？”

“并没有。我已经检查了它和它所调用的所有方法，甚至还看了它本身的filter和全局filter，并没有任何地方会清空cookie或者token缓存。只有清空这些才会自动登出。”

“对了，你是怎么发现调用完这个API后会被踢出的？”老夏接着问。

齐识调出了某个用户所有请求日志，定位到上传文件的请求。“你看，这个POST请求是上传文件，后面这些就是登出请求了，而前面的都是一些文件夹跳转的请求。这是其中一个用户的请求，这里还有其他用户。”说着，齐识又开了几个窗口，平铺在了显示器上。

“有意思。”老夏眯缝着眼睛紧盯着屏幕。“虽然他们都是上传完文件就被踢出了，但能确定就是上传文件的API导致的吗？是每次上传完文件都会登出吗？”

“还真不是！”

“而且别忘了IE，只有IE才会踢出用户不是么？那就更能洗清后台API的嫌疑了。”

“对啊老夏，我怎么没有想到？”齐识茅塞顿开。

“就像我连续两周都是周三喝普洱周四喝红茶，你认为那是某种必然。但这是你的主观臆断。主观判断一定要有事实作为依据，否则就都是臆断。”老夏说着，拿起茶壶晃晃悠悠地走了。

“等等，老夏，别走啊，我需要你！”

“我还有事。”老夏回过头冲齐识眨了眨眼睛说，“等你再需要我的时候我自然会出现的。”

3

他的表情不再那样淡漠，我看到他炯炯有神的双眼迸射出智慧和兴奋的光芒。——《格兰奇庄园》

齐识的目光又聚焦在了日志身上。如果用户真的在上传文件之后被踢出，一定能从日志中找到什么蛛丝马迹。齐识又换了一个留下的操作日志较多的用户，将日志按时间排好序。这个是登录成功的请求，这个是进入文件管理子系统的请求，这个是进入某个文件夹的请求，这个是心跳请求，然后上传文件，成功了，然后跳转到其他文件夹，继续上传文件，又发了个心跳，看看离上次心跳的间隔，嗯，2分钟，没有任何问题。齐识点击进入了下一页日志。

又进入了另一个文件夹，还是上传文件，成功了，然后……就登出了。这里面一定有什么猫腻。

齐识揉了揉眼睛，将所有注意力都集中到这几行日志身上，仿佛要看穿这屏幕，看到屏幕那头的另一个镜像的宇宙。

用户在15:32:26进入了第一个文件夹，15:32:45发送了第一个心跳请求，然后上传了第一个文件，15:33:20跳转到第二个文件夹，15:34:30上传第二个文件，15:34:45发送了第二个心跳请求，15:35:07进入第三个文件夹，15:37:48上传第三个文件，15:37:49，用户被踢出。

齐识目不转睛地盯着每个请求的发送时间，突然，他炯炯有神的双眼迸射出智慧和兴奋的光芒。用户在15:37:48上传第三个文件之前，丢失了一个心跳请求，这个心跳本应该在15:36:45发出来。

心跳怎么断了？如果是心跳断了，是必然会被踢出的，这样是解释得通的。但心跳怎么能断呢？齐识打开发心跳请求的JavaScript文件，就是一个简单的setInterval，没有什么特别的。是什么，让这个2分钟的轮询停止了呢？

老夏呢？老夏呢？这老家伙跑哪去了？他说过会在我需要的时候出现的，现在我需要你，可你人呢？我发现了重要的线索，已经锁定了嫌犯，现在就差证据了，就差证据了。

4

排除所有不可能，剩下的那个不管多不可思议，都是事实真相。——《四签名》

“老夏？他说今天要去幼儿园接孩子，提前下班了。”培训部的同事说。

齐识的一脸兴奋变成了一脸沮丧，他本想告诉老夏这个重要的发现，然后跟他一起找到问题的根本原因的。但老夏他居然提前下班走人了。

“你要有事，就给他打电话吧。”培训部的同事看齐识如此低落，就提醒道。

对呀，我怎么忘了这个世界上还有电话这么神奇的存在。齐识拨通了老夏的电话，没有人接。

“老夏，我有了重要的发现……”齐识把刚才的线索编辑成一条微信，发给了老夏。然后回到座位上接着分析。

用户前两次上传文件都没有问题，可是第三次就被踢出了。从时间轴来看，前两次进入文件夹后，都是很快便发出了上传文件的请求，唯独第三次，进入文件夹之后，停留了2分多钟才发出了请求。用户在干什么？进入文件夹后去喝茶聊天了？那样的话心跳没有理由断掉啊。

齐识启动IE，打开开发者工具，登录本地的系统，进入文件管理子系统，打开一个文件夹。接下来该干什么？齐识发呆了几分钟，一个心跳请求发送出去了。他回过神来，点击上传文件的按钮，弹出了选择文件的窗口。上传哪个文件呢？该死，电脑里没有PDF文件。这个文件管理系统只能上传PDF文件，并且做了文件头校验，直接改后缀名是不起作用的。于是齐识只好搜了一个TXT转PDF的在线转换工具，丢上去一个空的文本文件，得到了一个PDF。然后切回刚刚打开的系统，选择文件的窗口还开着。他找到转换好的PDF，点击按钮。然后，然后浏览器就自动跳转到了登录界面……

什么？复现了？这怎么可能？这么轻易就复现了？发生了什么？

齐识又进入系统，上传刚才转换好的PDF，一切正常。

闹鬼了？齐识把刚刚所有操作的日志拿出来看，第一次上传文件——也就是失败的那次——的时间，比进入文件夹晚了2分多钟，比上次心跳请求晚了3分多钟。按照系统的实现，超过3分钟没有心跳请求，后台会认为用户已经不活跃，将其自动登出。也就是完全复现了生产系统中用户的问题。而在此期间，齐识是去转换文件了。

齐识盯着日志，良久之后，哈哈哈哈地笑出了声。

5

通过搜索，齐识很快验证了自己的想法。在IE下，像JavaScript引发的alert窗口或file组件打开的窗口，都属于模态窗口，它们会阻塞所有主线程中正在执行的JavaScript代码。至于Chrome、Firefox这样的浏览器，打开的并不是模态窗口，这也就是为什么只有IE频繁报出类似的问题，其他浏览器则一直表现良好。当这种模态窗口一直处于打开状态时，心跳请求就被迫中断了，继而在上传成功后，被自动登出。

证据确凿，“凶手”就是你了！

一定要把这个消息告诉老夏。齐识拿起手机，看到老夏半个小时前的一条回复：是不是上传文件的窗口打开的时间太长了？

齐识不仅震惊，更是钦佩得五体投地。他把刚才的经过，一五一十地发给了老夏。过了一会儿老夏回复道：“哈哈哈，果然，是哪个笨蛋用户打开了窗口3分钟都找不到文件？等等，不对，不是3分钟，是1分钟！”

“没错，所以问题出现得还是很频繁的。”齐识又和老夏聊了几句，突然想起来什么，就问：“老夏，你明明不姓夏，可是为什么大家都叫你老夏呢？”

“呵呵，这次解决问题，或者叫探案的过程你感觉怎么样？”老夏似乎有点顾左右而言他，”我看前两天你桌上放着一本福尔摩斯探案集，想必也是个Sherlockian，那你一定听说过那句话吧？”

世界上没有真正完美的犯罪，其实真相一直就在我们眼前，只不过还没有被发现。所谓推理，不过就是把重要的细节放大。

当齐识和老夏同时打出这句话时，两个人都笑了。

6

“那个，我以前做开发的时候，大家都叫我夏洛克”。