枕边书

枕边书

最近有个需求需要统计一个方法的耗时，这个方法前后各打出一条日志，类似于 [INFO] 20180913 19:24:01.442 method start/end unique_id，unique_id 是我们框架为了区分每一个请求而生成的唯一ID。

由于在高并发场景下， start 和 end 的日志并不一定是挨着的，很可能方法执行期间，又有其他的日志输出了出来，于是产生了这样的日志：

[INFO] 20180913 19:24:01.442 method start aaa [INFO] 20180913 19:24:01.452 method start bbb [INFO] 20180913 19:24:01.456 do something ccc [INFO] 20180913 19:24:01.562 method end aaa ... 

由于日志在服务器上，不想再把日志 down 下来，又因为日志比较规范，于是决定自己写个 shell 脚本来处理这些数据。花了一下午时间，换了 4 个 shell 脚本，才优雅地处理了这些数据，其中走进了思维误区，踩了一个扩展问题的大坑。

Read full article from 枕边书