背景

我們生產(chǎn)環(huán)境有一個(gè)服務(wù)半夜報(bào)警：磁盤剩余空間不足10%，請及時(shí)處理。排查后發(fā)現(xiàn)是新上線的一個(gè)功能，日志打太多導(dǎo)致的，解決方法有很多，就不贅述了。領(lǐng)導(dǎo)擔(dān)心報(bào)警不及時(shí)、或者報(bào)警遺漏，擔(dān)心磁盤滿了對(duì)線上業(yè)務(wù)有負(fù)面影響，甚至不可用，令我研究一下該情況下對(duì)服務(wù)的影響。

正文

注：我們線上的應(yīng)用使用Logback日志框架進(jìn)行打印，所以log4j、log4j2或其它日志框架不在本次研究的范圍。

實(shí)驗(yàn)研究

實(shí)驗(yàn)步驟

1. 啟動(dòng)服務(wù)，觀察各項(xiàng)指標(biāo)正常（模擬正常工作的服務(wù)以及環(huán)境狀態(tài)）
2. 將磁盤寫滿
3. 觀察應(yīng)用服務(wù)、宿主機(jī)各項(xiàng)指標(biāo)，查看服務(wù)響應(yīng)是否正常（包括功能以及性能）
4. 將大文件刪除（恢復(fù)）
5. 重復(fù)第3步

實(shí)驗(yàn)過程

第1、3、5步重在觀測，不贅述。

第2步的模擬磁盤寫滿，使用linux的fallocate命令。

將磁盤寫滿的方式如下有幾種：

1. 自己寫文件，寫滿為止，速度較慢，有開發(fā)（寫腳本）成本
2. 使用dd命令，但是比較慢，取決于磁盤的速度
3. 使用truncate命令，但是該命令操作的結(jié)果并不占用實(shí)際的磁盤空間
4. 使用fallocate命令，fallocate -l {size} {fileName}，如fallocate -l 20G text1

我選擇了方式4，很快就寫滿了磁盤

驗(yàn)證方式：vim {xxx}，進(jìn)入文件編輯，寫入任意內(nèi)容，保存失敗并提示：Can't open file for writing(No space left on device)

實(shí)驗(yàn)結(jié)果

1. 磁盤寫滿前、后，應(yīng)用服務(wù)各項(xiàng)指標(biāo)均正常（功能、性能）
2. 磁盤寫滿后，服務(wù)器磁盤空間報(bào)警（無可用空間），刪除文件后報(bào)警恢復(fù)
3. 磁盤寫滿后，應(yīng)用日志停止打印，刪除文件后應(yīng)用日志恢復(fù)打印

即，磁盤滿了對(duì)于使用logback日志框架的應(yīng)用，并不會(huì)造成影響。

實(shí)驗(yàn)結(jié)果令人詫異，按正常理解，磁盤滿了之后再寫入，會(huì)報(bào)No space left on device異常，進(jìn)而影響到應(yīng)用程序的功能。

原理分析

logback配置文件里的文件appender如下（RollingFileAppender同理）：

<appender name="FILE" class="ch.qos.logback.core.FileAppender">
    <file>${LOG_HOME}/${APP_NAME}.log</file>
    <encoder>
        <pattern>%d{yyyy-MM-dd HH:mm:ss} [%thread] %-5level %logger{36} - %msg%n</pattern>
    </encoder>
</appender>

把關(guān)注點(diǎn)放到appender即可，因?yàn)樽罱K的日志輸出是由appender控制的：它控制寫在哪個(gè)文件里，格式是怎樣的，滾動(dòng)策略又是怎樣的。

通過IDEA查看RollingFileAppender的繼承關(guān)系如下下示：

image.png

將視線聚焦到ch.qos.logback.core.OutputStreamAppender#writeBytes，代碼如下：

private void writeBytes(byte[] byteArray) throws IOException {
    if(byteArray == null || byteArray.length == 0)
        return;

    lock.lock();
    try {
        this.outputStream.write(byteArray);
        if (immediateFlush) {
            this.outputStream.flush();
        }
    } finally {
        lock.unlock();
    }
}

由上可知，寫日志時(shí)會(huì)加鎖，避免資源競爭，然后通過outputStream寫出，接著馬上刷盤（默認(rèn)情況）。

這里的outputStream可了不得，是個(gè)ResilientFileOutputStream實(shí)例，顧名思議，【彈性的】FileOutputStream。它是個(gè)子類，核心邏輯在父類ResilientOutputStreamBase上，看看write方法：

public void write(byte b[], int off, int len) {
    if (isPresumedInError()) {
        if (!recoveryCoordinator.isTooSoon()) {
            attemptRecovery();
        }
        return; // return regardless of the success of the recovery attempt
    }

    try {
        os.write(b, off, len);
        postSuccessfulWrite();
    } catch (IOException e) {
        postIOFailure(e);
    }
}

這個(gè)write方法隱藏著【即使磁盤滿了也不影響業(yè)務(wù)】的秘密！它的核心邏輯是：如果能正常寫文件，就寫；如果寫入失?。ǔ霈F(xiàn)了IO異常），就抓住異常并切換至失敗狀態(tài)，接下來的一段時(shí)間都不再繼續(xù)寫文件，直接返回。

而此處所有的IO異常，就包含了No space left on device，因此，此處便是磁盤滿了之后繼續(xù)日志寫入，卻不會(huì)拋出No space left on device異常進(jìn)而影響業(yè)務(wù)的原因。

還有一個(gè)問題，待磁盤有剩余空間后，如何恢復(fù)日志寫入？上面實(shí)驗(yàn)結(jié)果提到，磁盤寫滿后，應(yīng)用日志停止打印，刪除文件后應(yīng)用日志恢復(fù)打印。因此必然會(huì)有一個(gè)策略，能夠在磁盤空間恢復(fù)后，繼續(xù)進(jìn)行日志寫入。

再仔細(xì)查看看write方法，方法首先判斷當(dāng)前狀態(tài)是否為“失敗”。若是，接著檢查自上次失敗至今的時(shí)間。如果已經(jīng)經(jīng)過了很長時(shí)間，就【嘗試恢復(fù)】。

void attemptRecovery() {
    try {
        close();
    } catch (IOException e) {
    }

    addStatusIfCountNotOverLimit(new InfoStatus("Attempting to recover from IO failure on " + getDescription(), this));

    // subsequent writes must always be in append mode
    try {
        os = openNewOutputStream();
        presumedClean = true;
    } catch (IOException e) {
        addStatusIfCountNotOverLimit(new ErrorStatus("Failed to open " + getDescription(), this, e));
    }
}

嘗試恢復(fù)的邏輯是：關(guān)閉舊文件流并重新打開文件流，將【失敗】狀態(tài)切換至【半恢復(fù)】狀態(tài)，此處并未完全進(jìn)入【正?！繝顟B(tài)，而是立即返回，即是說當(dāng)次的日志記錄請求并不會(huì)寫文件。

下次的日志寫入，才會(huì)嘗試將日志寫入文件

• 若日志成功寫入文件，就將狀態(tài)切換至【正?！繝顟B(tài)。
• 若日志寫入文件失敗，就將狀態(tài)切換至【失敗】狀態(tài)。

此處的失敗以及恢復(fù)邏輯非常像Hystrix斷路器，即經(jīng)歷一個(gè)正?！　胪窢顟B(tài)，通過下次請求的結(jié)果來決定是恢復(fù)正常還是保持失敗。

上面提到若經(jīng)過很長時(shí)間，就嘗試恢復(fù)，這里的【很長時(shí)間】其實(shí)是一個(gè)泛指，它有自己的時(shí)間計(jì)算邏輯，此處采用了類似于RocketMQ在消費(fèi)失敗時(shí)的重試策略，即采用指數(shù)退避邏輯來控制重試時(shí)間間隔。

每次【半恢復(fù)】狀態(tài)下寫文件失敗時(shí)，會(huì)保持【失敗】狀態(tài)，且每一次的失敗寫入都會(huì)指數(shù)級(jí)延長【失敗】狀態(tài)保持的時(shí)間。

public boolean isTooSoon() {
    long now = getCurrentTime();
    if (now > next) {
        next = now + getBackoffCoefficient();
        return false;
    } else {
        return true;
    }
}

private long getBackoffCoefficient() {
    long currentCoeff = backOffCoefficient;
    if (backOffCoefficient < BACKOFF_COEFFICIENT_MAX) {
        backOffCoefficient *= BACKOFF_MULTIPLIER;
    }
    return currentCoeff;
}

backOffCoefficient初始值：20

BACKOFF_COEFFICIENT_MAX：327680

BACKOFF_MULTIPLIER：4

總結(jié)

使用Logback日志框架，當(dāng)磁盤滿了后不必驚慌，它不會(huì)對(duì)應(yīng)用程序產(chǎn)生太負(fù)面影響。仔細(xì)考慮，做為一個(gè)日志框架本該如此，不能因?yàn)閷懖涣巳罩揪蛼伋霎惓＿M(jìn)而影響應(yīng)用本身，畢竟，日志終究是個(gè)輔助的旁路邏輯，沒有它應(yīng)用也應(yīng)該work well。

底層知識(shí)的掌握有助于迅速理解上層應(yīng)用。在閱讀源碼的過程中，我發(fā)現(xiàn)了非常熟悉的設(shè)計(jì)邏輯：即類似于Hystrix的斷路器和RocketMQ消費(fèi)失敗重試的策略。由于之前有相關(guān)經(jīng)驗(yàn)，因此我很快就能夠理解作者的設(shè)計(jì)意圖。

注：事后我測試了一下Log4j2日志框架，表現(xiàn)也差不多，磁盤滿了也不會(huì)對(duì)應(yīng)用程序本身產(chǎn)生影響。