一個線上Java空指針問題的排查經過

某天，運營反饋，某商品下單異常

1.原來是一個空指針報錯

根據用戶輸入的下單關鍵信息搜索日志系統看到如下報錯

stackTrace: "java.lang.NullPointerException
	at com.auto.order.service.utils.OrderingUtils.buildParentOrderData(OrderingUtils.java:194)
	at com.auto.order.service.cart.impl.OrderingCommonServiceImpl.handleStat(OrderingCommonServiceImpl.java:1221)
	at com.auto.order.service.cart.impl.OrderingIndexServiceImpl.receive(OrderingIndexServiceImpl.java:1027)
	at com.auto.order.service.impl.OrderApiServiceImpl.receive(OrderApiServiceImpl.java:1979)
	at com.auto.order.site.controller.neworder.OrderingIndexController.receive(OrderingIndexController.java:368)

原來是個空指針錯誤，來看下194行代碼是啥

1 parentOrderData.setRefCookie(orderingReceiveParamBo.getRefCookie());
2 parentOrderData.setCityId(orderingReceiveParamBo.getRuleCityId().intValue());//194行
3 parentOrderData.setSessionId(orderingReceiveParamBo.getSessionId() != null ? orderingReceiveParamBo.getSessionId() : ""); 

上面代碼塊第二行就是原文件里194行，判斷得出應該是ruleCityId字段為空導致了空指針異常；又看了下parentOrderData對象和orderingReceiveParamBo對象的ruleCityId字段都是Integer類型，這里沒有必要intValue，改之如下

2 parentOrderData.setCityId(orderingReceiveParamBo.getRuleCityId());//194行

 上線后，以為問題就解決了呢，誰知依舊報錯，繼續翻看日志，發現如下報錯

--- Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: Column 'city_id' cannot be null
	at org.springframework.jdbc.support.SQLStateSQLExceptionTranslator.doTranslate(SQLStateSQLExceptionTranslator.java:102)
	at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:73)
	at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:82)
	at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:82)

2.看來不僅僅是一個空指針

數據庫里設置了city_id字段是非空的，但是程序沒有獲取到city_id，為啥獲取不到呢，繼續排查city_id是怎么獲取的

/**
 * 獲取所在城市
 */
public static int mallCityId(HttpServletRequest request){
    try {
        String ck = getCookieValue(request.getCookies(), "cookieCityId");
        if ( "999999".equals(ck)) {
            return 110100;
        }
        if (StringUtils.isNotBlank(ck) && Integer.parseInt(ck) > 0) {
            return ck.indexOf("9999") > 0 ? Integer.parseInt(ck.substring(0, 2) + "0100") : Integer.parseInt(ck.substring(0, 4) + "00");
        }
        ck = getCookieValue(request.getCookies(),"area");
        if ("999999".equals(ck)) {
            return 110100;
        }
        if (StringUtils.isNotBlank(ck) && Integer.parseInt(ck) > 0) {
            return ck.indexOf("9999") > 0 ? Integer.parseInt(ck.substring(0, 2) + "0100") : Integer.parseInt(ck.substring(0, 4) + "00");
        }
    } catch (Exception e) {
        indexLog.error("mallCityId is error!",e);
    }
    return 110100;
}

　　

代碼中city_id是從cookie中獲取的，但是這一段代碼返回結果不可能為null，即使有異常，也該返回默認城市110100！繼續看哪里調用了這個方法，原來是在攔截器方法里調用了這個方法取各種cookie，並做容錯處理，主要代碼如下

/**
     * 方法執行前的攔截方法
     */
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
        String sessionId = "";
        Long pvId = 0L;
        Long positionId = 0L;
        Integer cityId = 0;
        String sessionVid = "";
        String refCookie = "";
        String sessionIp="";

        Long s = System.currentTimeMillis();
        try {
            sessionId = getCookieValue(request.getCookies(),"sessionid");
            sessionVid = getCookieValue(request.getCookies(),"sessionvid");
            sessionIp = getCookieValue(request.getCookies(),"sessionip");
            pvId = Long.valueOf(StringUtils.isNotBlank(getCookieValue(request.getCookies(), "mpvareaid")) ? getCookieValue(request.getCookies(), "mpvareaid") : "0");
            positionId = Long.valueOf(StringUtils.isNotBlank(getCookieValue(request.getCookies(), "autohomeareaid")) ? getCookieValue(request.getCookies(), "autohomeareaid") : "0");
            cityId = mallCityId(request);
            request.setAttribute(CUR_SESSION_ID,sessionId);
            request.setAttribute(CUR_SESSION_IP,sessionIp);
            request.setAttribute(CUR_SESSION_VID,(sessionVid == null?"":sessionVid));
            request.setAttribute(CUR_REF_COOKIE,(refCookie == null?"":refCookie));
            request.setAttribute(CUR_PV_ID,pvId);
            request.setAttribute(CUR_POSITION_ID,positionId);
            request.setAttribute(CUR_CITY_ID,cityId);
            request.setAttribute(PARTNER, getCookieValue(request.getCookies(), PARTNER));
            request.setAttribute(CURR_UNIX_TIME, System.currentTimeMillis());
        } catch (Exception e) {
            log.error("get interceptor error：", e);
        }
        timeLog.info("interceptor end   timecost=======>"+(System.currentTimeMillis()-s));
        return true;
    }

　　這個攔截器方法，粗看下去沒有發現任何問題，如果這個方法有異常，但是日志系統死活沒有看到catch打印的error堆棧信息；如果沒異常，按流程走下來，cityId字段不可能為空啊！怎么辦，笨方法，加日志，我把這個方法調用 mallCityId 方法之上每隔一行都加了日志，看哪行有貓膩

　　通過加日志定位到了問題所在，上面代碼塊的第18行一直走不到，18行就是這個

pvId = Long.valueOf(StringUtils.isNotBlank(getCookieValue(request.getCookies(), "mpvareaid")) ? getCookieValue(request.getCookies(), "mpvareaid") : "0");

　　仔細看這一行，真有可能出了問題，如果從cookie里取出來的不是數字，還要 Long.valueOf 肯定就報錯了，But為啥捕獲不到異常，再看catch塊log打印到哪里了

    private static Logger log = LoggerFactory.getLogger(CommonInterceptor.class);
    private static final Logger timeLog = LoggerFactory.getLogger("creat-order-time");
    private static final Logger indexLog = LoggerFactory.getLogger("access-index");

　　log對應的是 CommonInterceptor.class ，但是log4j2.xml文件里並沒有配置這個類文件，其他兩個日志文件在log4j2.xml文件里都有配置，唯獨這個CommonInterceptor.class 沒有映射，那日志打印到哪里了呢？最后在tomcat的catalina.out文件看到了報錯

　　上圖報錯行，正好對應的就是攔截器里第18行，從cookie里取出來的mpvareaid是undefined，所以類型轉換就報錯了，但是由於缺少log4j日志配置，沒有在常規業務日志路徑捕獲到該異常。最后把業務日志路徑改了，兼容了undefined情況，問題最終解決

3.總結兩點

　　第一：未兼容從cookie里取出來的異常數據undefined

　　第二：日志打印不規范，沒有合理配置日志路徑