REST服務中的日志可視化（關鍵技術實現）

引言

在系統構建完成之后，我們通常會使用REST API對外提供服務，在REST API的處理過程中經常會出現一些異想不到的問題（用戶權限不足、參數不全、數據庫訪問異常等），導致請求失敗，很多時候用戶並不能理解這些失敗是如何造成的，他們更多的是直接找到相應的開發者詢問：“我的這個接口失敗了，沒有拿到數據，幫忙看一下吧”，更為復雜的是當我們詢問其他用戶的時候，他們卻說：“你這個接口是正常的啊”，開發者這時就很郁悶：“我又沒對你做特殊處理，怎么別人是好的，偏偏就你的失敗”（本人在工作初期，經常遇到此類場景，表示很無奈）。

問題還是要解決，怎么辦？找日志唄！打開終端、拿起微盾、輸入密碼、輸入IP，等等！！！我們的REST API是部署在多台服務器上，前面有一台Nginx，“我去，誰知道是哪台服務器處理你的請求的，哦，我們在日志目錄下掛載了NFS，每個REST API的日志信息會寫入到一個固定的文件夾中”，“你什么時候請求這個接口的”，然后估計一個大概的時間，找到對應的日志文件（日志輸出使用Log4j，並按照天進行滾動），“我X，這個接口訪問如此頻繁，日志全部都混在了一起，怎么找”，“對了，我們有RequestID，每個請求都是唯一的，快找”，“我X，RequestID並不是每行日志都帶有的，完了”，日志無法定位，無顏面對用戶呀，只好羞愧地對用戶說：“我們有測試環境，我給你一個IP，你再訪問一次，我看看日志就知道啥原因了”。

多么高大上的回答呀，還是掩飾不住尷尬的內心，唉...

問題終歸是要解決的，把程序員（尤其是我）搞的不耐煩了，就要有創新了（自誇一下），另外得知我們的小伙伴們提供ELK服務，REST API日志可視化的想法油然而生。

注：本文僅關注在REST環境下如果自定義日志輸出，不涉及ELK部分（其他小伙伴支持，團隊的力量）

關鍵問題

REST API中使用log4j進行日志輸出，如何在不影響現有代碼的基礎上（無須在業務代碼中添加任何代碼），收集一次請求的日志信息，透明的將日志輸出至ELK

解決思路

（1）使用ServletRequestListener對請求過程進行監聽，請求過程包含兩部分：requestInitialized、requestDestroyed；
（2）每一次請求的初始化、處理、銷毀是由一個獨立的線程負責完成的（熟悉Java的同學可能立馬就會想到ThreadLocal）；
（3）現有業務代碼中已經使用log4j作日志輸出，為了保證不影響現有代碼及以后的開發，唯一的方式，自定義Appender；

通過上述三步，我們可以大致得出這樣一個流程：

（1）在ServletRequestListener requestInitialized初始化當前線程的日志對象；
（2）業務代碼執行過程中，log4j輸出日志時通過我們自定義的Appender，將日志信息保存至當前線程的日志對象中；
（3）在ServletRequestListener requestDestroyed中將當前線程的日志對象中的日志信息輸出至目的地（這里是ELK，也可以是其它），然后清空線程對象。

注意：以上全部操作均依賴於一個請求過程的處理全部處於一個線程環境中。

解決方案

（1）定義日志對象

public class DipLog {

    public static class DipLogMessage {

        private String time;

        private String level;

        private String filename;

        private String className;

        private String methodName;

        private String lineNumber;

        private String message;

        public DipLogMessage(String time, String level, String filename,
                String className, String methodName, String lineNumber,
                String message) {
            this.time = time;

            this.level = level;

            this.filename = filename;

            this.className = className;

            this.methodName = methodName;

            this.lineNumber = lineNumber;

            this.message = message;
        }

        public String getTime() {
            return time;
        }

        public String getLevel() {
            return level;
        }

        public String getFilename() {
            return filename;
        }

        public String getClassName() {
            return className;
        }

        public String getMethodName() {
            return methodName;
        }

        public String getLineNumber() {
            return lineNumber;
        }

        public String getMessage() {
            return message;
        }

        @Override
        public String toString() {
            return String.format("%s\t%s\t%s\t%s\t%s\t%s\t%s", time, level,
                    filename, className, methodName, lineNumber, message);
        }

    }

    private Map<String, String> properties = new HashMap<String, String>();

    private List<DipLogMessage> messages = Collections
            .synchronizedList(new ArrayList<DipLog.DipLogMessage>());

    public void addProperty(String key, String value) {
        properties.put(key, value);
    }

    public void addMessage(DipLogMessage message) {
        messages.add(message);
    }

    public Map<String, String> getProperties() {
        return properties;
    }

    public List<DipLogMessage> getMessages() {
        return messages;
    }

}

 

properties中保存一些自定義屬性值（log4j本身不支持的），messages中保存通過log4j debug、info、warn、error輸出的日志消息（DipLogMessage ）。

（2）通過ThreadLocal保存一個請求處理過程中的日志對象

public class DipLogThreadLocal {

    private static final ThreadLocal<DipLog> DIP_LOG_THREAD_LOCAL = new ThreadLocal<DipLog>();

    public static DipLog get() {
        return DIP_LOG_THREAD_LOCAL.get();
    }

    public static void set(DipLog dipLog) {
        DIP_LOG_THREAD_LOCAL.set(dipLog);
    }

    public static void clear() {
        DIP_LOG_THREAD_LOCAL.set(null);
    }

}

 

（3）擴展Log4j，自定義Appender，將請求處理過程中的日志消息保存至當前線程關聯的日志對象中

public class DipLogAppender extends WriterAppender {

    private static final SimpleDateFormat DATETIME_FORMAT = new SimpleDateFormat(
            "yyyy-MM-dd HH:mm:ss,SSS");

    @Override
    public void append(LoggingEvent event) {
        String time = DATETIME_FORMAT.format(new Date(event.getTimeStamp()));

        String level = event.getLevel().toString();

        String filename = event.getLocationInformation().getFileName();

        String className = event.getLocationInformation().getClassName();

        String methodName = event.getLocationInformation().getMethodName();

        String lineNumber = event.getLocationInformation().getLineNumber();

        String message = event.getRenderedMessage();

        DipLogMessage dipLogMessage = new DipLogMessage(time, level, filename,
                className, methodName, lineNumber, message);

        DipLog dipLog = DipLogThreadLocal.get();

        dipLog.addMessage(dipLogMessage);
    }

}

 

(4)創建ServletRequestListener

public class DipLogRequestListener implements ServletRequestListener {

    @Override
    public void requestInitialized(ServletRequestEvent event) {
        DipLog dipLog = new DipLog();

        dipLog.addProperty("requestId", String.valueOf(System.currentTimeMillis())); dipLog.addProperty("url", ((HttpServletRequest) event .getServletRequest()).getRequestURI());

        DipLogThreadLocal.set(dipLog);
    }

    @Override
    public void requestDestroyed(ServletRequestEvent event) {
        DipLog dipLog = DipLogThreadLocal.get();

        Map<String, String> properties = dipLog.getProperties(); for (Entry<String, String> entry : properties.entrySet()) { System.out.println(entry.getKey() + "\t" + entry.getValue()); } List<DipLogMessage> messages = dipLog.getMessages(); for (DipLogMessage dipLogMessage : messages) { System.out.println(dipLogMessage); }

        DipLogThreadLocal.clear();
    }

}

 

從黑體部分代碼可以看出，我們在日志對象中保存着當前請求的RequestID及URL（可以添加到最后的日志消息輸出），通過requestDestroyed完成請求日志消息的具體輸出（這里僅僅模擬，直接輸出至控制台）。

這里僅僅介紹核心實現，可以在此基礎之上根據業務需求擴展出更為復雜的功能。