IT咨询顾问:一次吐血的项目救火
年后的一个合作公司上线了一个子业务系统,对接公司内部的单点系统。我收到该公司的技术咨询:项目启动后没有规律的突然无法登录了,重新启动后,登录一断时间后又无法重新登录,对方技术人员一头雾水不知道什么原因,后台日志没有任何错误信息。我临危受命,赶往该项目进行扑火工作,其实本来2天都可以解决的问题,让我花了5天解决。具体原因待我一一解释。
1,未掌握log日志的精髓
log日志的debug,info,error信息乱打,该用debug的用info,该用info的用debug......,导致的结果就是一个登陆成功请求,后台日志打了300行代码,严重影响了排查追踪问题的效率,项目线上日志级别仍为debug级别,换成info级别呢,结果好多关键信息又没有打印。
日志输出格式的关键信息不完善,该日志是在哪类目名、发生的线程,以及在代码中的行数都没有清楚的显示出来,这个日志是哪里打印的都无从知晓。
关于这里,我想说的是,先用技术的深度再有技术的广度,日志是内功,它是日后面对各种线上问题能够快速排查的一种手段。
下面这个是他的日志输出:
2,核心参数不做判断
方法返回的数据不做null或""字符串判断,导致各种情况的空指针异常。项目的功能都是理想化,预想我就是需要这些数据才能给你正确的结果,否则哪里出错我不知道。这个问题导致我在还原案件现场时给我造成极大的困惑,一不留神一个空指针错误,我必须对这个错误进行加强的判断处理,好方便我模拟出登录多次后无法登录的情况。
另外项目中sql语句的in的使用不规范,结合前面的null判断没有,出现一种:"咦,我用这个账号登录就成功了,sql是正确的,用这个人的账号登录,怎么就报sql语法不正确啊,明明调用的是同一块的代码啊"
很明显的roleid为"'字符串的话,这条sql语句的语法是由问题的。
3,局部变量提升为静态变量
这个是文章开头提的问题的原因,因为登录要向单点系统验证用户的身份,所以它采用httpclient框架来发送http请求,它在这里把httpclient的变量作为一个静态变量,然后在方法里面复用该对象,然后方法里面调用完该对象又没有释放资源合理的close,这个框架默认会维护一个连接池,如果你申请一个资源使用后不释放,那么该资源将不被下一个请求使用,新的请求必须在等待队列中等待,然后当用户登录20次后,把资源池中的请求都耗尽了,新的请求拿不到资源位于等待队列中不断等待,导致服务器超时,登录失败504错误。
当时我看到这个类的静态变量时httpclient的时候,我心中就飘起不好的预感,此处是一个容易出错的地方,如果是我,对这个框架,这个类没有十足的把握,我会它把整成局部变量,这样在低并发下,就让GC去帮我回收吧。
改造后:
4,拦截器的路径规划混乱
这个问题也为我排查问题造成了阻碍,排查登录问题,我首先要把它一次登录成功后后端走的方法轨迹追踪出来,看到底是哪一个环节的代码问题,因为没有任务错误信息。他的拦截器呢,一个登录请求成功拦截器反复执行了三次,中间至少有一次拦截器是没有做任何有效出来,出现这的问题是他前端业务发送无关的请求,被拦截导致的,这个逼得我通过日志插桩计数来还原勾勒出它的完整路径,为我审查代码找到调用httpclient这一块的代码问题提供的机会。
5,乱用try catch
这个也很恶心,它的代码突然try catch包装一下,咦,这个家伙得不错,还对某些异常进行特殊打标记录,我仔细看了一下代码,这是什么鬼啊,catch中怎么把异常信息吃了,吃了就吃了,你为啥也不打印异常信息,也不throws异常,就这样凶猛的将异常吃了,明明有问题,它不报,通过它来引发一个新的异常来雪藏真正的问题。
最后我想说,程序员何苦难为程序员,代码留一线, 日后好相见啥。你也不想自己给自己挖坑后,解决不了,然后来一句"大哥,你忙吗,我这有个小问题,帮忙看下呗(嗑瓜子)"。