杜比播放服務(wù)器日志原理及分析方法的探究

許 鵬

（杜比實(shí)驗(yàn)室國(guó)際技術(shù)服務(wù) （上海）有限公司，上海200030）

眾所周知，數(shù)字電影播放服務(wù)器是以傳統(tǒng)計(jì)算機(jī)硬件架構(gòu)所組成的，運(yùn)行在Linux操作系統(tǒng)上，符合DCI規(guī)范的專用電影播放服務(wù)器。在實(shí)際使用中若播放服務(wù)器出現(xiàn)故障，如何快速準(zhǔn)確地定位故障，找到故障根本原因，除了使用排除法、替換法、比較法等常規(guī)故障排摸方法，熟練掌握播放服務(wù)器日志分析法這一技能將事半功倍。

播放服務(wù)器系統(tǒng)日志是指播放服務(wù)器在運(yùn)行過(guò)程中產(chǎn)生的事件記錄。這些記錄被系統(tǒng)程序收集歸檔并存放到文件中，生成系統(tǒng)日志文件。日志文件詳細(xì)記載著所發(fā)生事件的類型、時(shí)間、相關(guān)進(jìn)程、操作描述及信息級(jí)別。數(shù)字電影播放服務(wù)器日志不僅有常規(guī)的操作系統(tǒng)日志，比如系統(tǒng)內(nèi)核 （kernel）日志，網(wǎng)絡(luò)服務(wù)日志 （Apache）等，還包含了多個(gè)專用的設(shè)備日志，如播放日志、安全管理器日志等全面記錄播放服務(wù)器的歷史事件。顯然，日志中包含了很多有用的信息和線索，通過(guò)查看日志可大體掌握設(shè)備的配置信息、歷史事件、維護(hù)狀態(tài)和告警及錯(cuò)誤消息，有利于快速判斷故障。雖然日志分析很有用，但是日志中信息量巨大，學(xué)習(xí)掌握難度也大。如要在巨量的數(shù)據(jù)中提取有用的信息，必須擁有扎實(shí)的基礎(chǔ)知識(shí)并掌握一些實(shí)用的技巧。如果沒(méi)有掌握有效的方法和知識(shí)的積累，那么只會(huì)在信息的海洋中迷失，從而無(wú)功而返。

1 播放服務(wù)器日志的結(jié)構(gòu)和相關(guān)原理

首先，最重要的是了解播放服務(wù)器日志的結(jié)構(gòu)和相關(guān)原理，以下以杜比服務(wù)器Show Vault的日志為例作具體說(shuō)明。如圖1所示。

圖1 杜比服務(wù)器Show Vault的日志

下載的杜比播放服務(wù)器日志是一個(gè)以.tgz擴(kuò)展名結(jié)尾的壓縮文件，例如drmreport_230068_2019_10_05.tgz。從命名中可以得知該播放服務(wù)器的媒體模塊序列號(hào)為230068，日志獲取的時(shí)間為2019年10月5日。當(dāng)解壓縮該文件后，會(huì)得到另外兩個(gè)壓縮文件drmreport.tgz和sbcreport.tgz，還有一個(gè)重要的文本文件drmreport.txt。當(dāng)在用戶界面點(diǎn)擊下載播放服務(wù)器日志時(shí)，系統(tǒng)會(huì)在后臺(tái)執(zhí)行多個(gè)命令，并把這些指令和運(yùn)行結(jié)果存放到這個(gè)日志文件中。因此可以把drmreport.txt看作為播放服務(wù)器的系統(tǒng)報(bào)告，里面包含了軟件版本、安全時(shí)鐘、磁盤(pán)陣列、硬盤(pán)信息、網(wǎng)絡(luò)信息等諸多內(nèi)容，非常重要。當(dāng)再次解壓縮drmreport.tgz文件，進(jìn)入/doremi/log目錄中，會(huì)發(fā)現(xiàn)大量帶有后綴名為.log的文件。這就是播放服務(wù)器的設(shè)備日志，其總體數(shù)量在120個(gè)左右，每個(gè)日志文件記錄著不同軟件子系統(tǒng)的事件信息。由此可見(jiàn)，杜比播放服務(wù)器根據(jù)軟件子系統(tǒng)的功能將日志文件分門(mén)別類列出，不僅數(shù)量多，而且信息量大。必須搞清楚主要日志文件的功能屬性和工作原理，避免大海撈針，才能有的放矢地去正確的位置尋找線索。表1挑出了重要的日志文件做簡(jiǎn)要說(shuō)明。

表1 重要日志文件的簡(jiǎn)要說(shuō)明

例如，通過(guò)bootseq.log 日志可檢查用戶非法關(guān)機(jī)的行為。當(dāng)發(fā)現(xiàn)日志中每天都重復(fù)出現(xiàn)“［WARNG］：boot sequence-check：Invalid boot sequence detected”這條記錄時(shí)，可明確判定用戶是否按照正常流程關(guān)閉服務(wù)器，因此當(dāng)下一次開(kāi)機(jī)時(shí)，系統(tǒng)會(huì)在日志中自動(dòng)記錄非法關(guān)機(jī)的行為。這類操作的不良后果可能會(huì)導(dǎo)致系統(tǒng)文件丟失甚至操作系統(tǒng)崩潰，需及時(shí)提醒用戶改變操作習(xí)慣，防范于未然。又如，drm_errorsummary.log收集了播放服務(wù)器歷史上所有的錯(cuò)誤時(shí)間，并做了故障歸類。分析日志時(shí)應(yīng)優(yōu)先打開(kāi)該日志，快速掌握全局情況，再到相關(guān)日志中查找線索，驗(yàn)證細(xì)節(jié)。這樣可大量節(jié)約時(shí)間，提高效率。

2 播放服務(wù)器日志分析

了解日志文件的結(jié)構(gòu)和其功能屬性后，還需要結(jié)合計(jì)算機(jī)、英語(yǔ)等綜合知識(shí)，才能更好地理解并分析日志。筆者根據(jù)自身經(jīng)驗(yàn)總結(jié)了6條經(jīng)驗(yàn)法則以供參考：

（1）日志分析應(yīng)具備良好英語(yǔ)能力和Linux系統(tǒng)知識(shí)

日志的語(yǔ)言環(huán)境是英語(yǔ)，雖然每條日志不長(zhǎng)，語(yǔ)法不難，但是需要掌握大量的英語(yǔ)專業(yè)詞匯，理解其特殊的含義，這是讀懂日志的基礎(chǔ)。例如，杜比播放服務(wù)器日志中有一個(gè)頻繁出現(xiàn)的單詞是“Dolphin”，普通意譯為 “海豚”，在播放服務(wù)器環(huán)境中它是媒體模塊的代號(hào)。其次，還要掌握Linux系統(tǒng)的相關(guān)知識(shí)，包括Linux文件和目錄、操作指令等。

上述提到的drmreport.txt文件里包含了大量在系統(tǒng)生成日志時(shí)執(zhí)行的指令和返回的結(jié)果。了解這些指令的意義，可直接判斷該子模塊的狀態(tài)。例如：其中一條命令為 “cat/etc/timezone”，返回結(jié)果為 “Asia/Shanghai”，便可得知服務(wù)器所在的時(shí)區(qū)。

（2）日志分析應(yīng)具備較強(qiáng)的邏輯推理能力

日志文件是由大量的信息所組成的，有用的信息可能散布在一個(gè)或多個(gè)不同的文件中。這就需要我們有較強(qiáng)的邏輯推理能力，根據(jù)故障發(fā)生的時(shí)間節(jié)點(diǎn)，在不同日志文件中找尋線索，反復(fù)比對(duì)在該時(shí)間點(diǎn)所發(fā)生的事件，串聯(lián)起來(lái)推理問(wèn)題，綜合判斷故障的原因。

（3）善于查找關(guān)鍵詞

所謂關(guān)鍵詞是指日志中頻繁出現(xiàn)并賦有特殊意義的英語(yǔ)單詞，它們的反復(fù)出現(xiàn)往往暗示著故障已經(jīng)發(fā)生。善于利用關(guān)鍵詞的查找，無(wú)疑是日志初學(xué)者快速定位故障的捷徑。例如關(guān)鍵詞 “underflow”表示數(shù)據(jù)溢出，可能是硬盤(pán)或節(jié)目包的問(wèn)題。又如“decoder crash”表示出現(xiàn)了解碼錯(cuò)誤，故障大多與媒體模塊IMB板有關(guān)。通過(guò)搜索關(guān)鍵詞，可節(jié)省大量時(shí)間，快速找到相關(guān)線索。

（4）運(yùn)用合適的工具能事半功倍

日志文件的內(nèi)容大多是可讀的本文，如果直接用windows自帶的記事本打開(kāi)的話，所顯示的日志會(huì)是雜亂無(wú)章，看得人一頭霧水。建議大家使用notepad++或UltraEdit打開(kāi)日志文件，這類軟件會(huì)將每條日志有序排列，并標(biāo)注行號(hào)，這樣可以一目了然獲取每行日志的時(shí)間、信息級(jí)別、相關(guān)程序及事件描述等信息。另外，還可以運(yùn)用軟件的高級(jí)搜索、關(guān)鍵字標(biāo)記、雙屏閱讀等功能提高日志的可讀性。其次，還應(yīng)該充分利用每家設(shè)備廠商的定制化日志分析軟件和工具。杜比播放服務(wù)器使用的是在線日志分析網(wǎng)站，用戶可以將日志上傳到網(wǎng)站，系統(tǒng)會(huì)自動(dòng)分析日志后，詳細(xì)列出播放服務(wù)器的基本信息，警告和故障條目，并逐一給出故障解決方案。

（5）日志不是萬(wàn)能的，不是所有問(wèn)題都記錄

這是初學(xué)日志分析需要注意的地方，日志中不會(huì)包含所有的信息，也不會(huì)記錄所有的問(wèn)題。比如杜比播放服務(wù)器電源發(fā)生故障，是不會(huì)記錄在任何日志中。又如，當(dāng)影廳內(nèi)出現(xiàn)雜音的情況，由于播放服務(wù)器不能對(duì)音頻信號(hào)輸出做監(jiān)控和檢查，日志中自然不會(huì)記錄這類故障。日志分析只是故障判斷的一個(gè)輔助手段，大多時(shí)候很有用，但也不是萬(wàn)能的。

（6）部分日志是研發(fā)代碼和機(jī)器語(yǔ)言，不要奢望完全讀懂日志

當(dāng)讀取日志文件時(shí)，總會(huì)發(fā)現(xiàn)一些令人百思不得其解的專業(yè)代碼和機(jī)器語(yǔ)言，這是很正常的。除非你參與了整個(gè)產(chǎn)品的研發(fā)過(guò)程，否則很難面面俱到，從頭到尾弄清楚每一行日志的含義。運(yùn)用日志分析的目的，在于從信息的海洋中找到有效、易懂的信息，來(lái)輔助判斷問(wèn)題。只要能夠掌握大部分有用的信息，并理解它表示的含義，同樣的可達(dá)到較好的效果，而不必過(guò)分咬文嚼字，糾結(jié)于細(xì)節(jié)。

3 案例說(shuō)明

下面通過(guò)三個(gè)實(shí)際案例來(lái)更好地說(shuō)明如果利用日志來(lái)查找線索，分析故障可能發(fā)生的原因。

案例1：Show Vault播放服務(wù)器放映中頻繁出現(xiàn)卡頓的故障現(xiàn)象

根據(jù)此現(xiàn)象，不難判斷出是由播放服務(wù)器磁盤(pán)陣列中的一塊或多塊硬盤(pán)或媒體模塊解碼故障所引起的。首先，解壓縮日志后打開(kāi)rm_errorsummary.log，該日志的功能是收集所有子系統(tǒng)的錯(cuò)誤日志并歸檔列出。在這個(gè)案例中，日志里列出了大量有關(guān)硬盤(pán)的錯(cuò)誤記錄如圖2所示。

圖2 硬盤(pán)報(bào)警日志

md0是存儲(chǔ)節(jié)目的系統(tǒng)分區(qū)，SDC和ata3都對(duì)應(yīng)于第三塊硬盤(pán)，從中看出該硬盤(pán)發(fā)生了大量的讀寫(xiě)錯(cuò)誤，并被系統(tǒng)標(biāo)記為媒體錯(cuò)誤。隨后，再打開(kāi)關(guān)于硬盤(pán)狀態(tài)的drmreport.log去找尋更多的線索。搜索關(guān)鍵詞mdstat可快速定位磁盤(pán)陣列和硬盤(pán)狀態(tài)的相關(guān)信息如圖3和圖4所示。

圖3 磁盤(pán)陣列狀態(tài)

md1的標(biāo)記符 ［4/3］［UU_U］表示了擁有4塊硬盤(pán)的磁盤(pán)陣列系統(tǒng)已經(jīng)處于降低運(yùn)行，第三塊硬盤(pán)SDC已經(jīng)被磁盤(pán)陣列移除。

圖4 硬盤(pán)SMART 信息

隨后進(jìn)一步檢查第三塊硬盤(pán)的SMART 值，其中1、5、197項(xiàng)的數(shù)值顯示異常，遠(yuǎn)超出標(biāo)準(zhǔn)范圍，表明該硬盤(pán)有存在大量底層讀寫(xiě)錯(cuò)誤和重新分配的扇區(qū)數(shù)，已無(wú)法自行修復(fù)，必須及時(shí)更換。

最后，可以打開(kāi)播放日志odeticsd.log，從中搜索關(guān)鍵詞underflow，匹配出多個(gè)錯(cuò)誤記錄，同時(shí)顯示了當(dāng)時(shí)所播放的節(jié)目信息。如圖5所示。

圖5 odeticsd日志

由此可見(jiàn)，經(jīng)過(guò)多個(gè)日志的驗(yàn)證和分析，可以準(zhǔn)確地定位到第三塊硬盤(pán)是發(fā)生卡片故障的根本原因?？紤]到硬盤(pán)故障可能是隱形的，即圖形界面中不告警，狀態(tài)指示燈仍有可能是綠色，因此通過(guò)日志來(lái)判斷無(wú)疑更加直觀準(zhǔn)確。

案例2：Show Vault播放服務(wù)器放映中圖像異常

與圖像有關(guān)的問(wèn)題應(yīng)先定位故障的源頭是放映機(jī)還是播放服務(wù)器，可通過(guò)檢查放映機(jī)通道設(shè)置并播放放映機(jī)內(nèi)部測(cè)試圖來(lái)檢查。如果排除了放映機(jī)的嫌疑，仍有條紋或閃爍這類故障現(xiàn)象，應(yīng)重點(diǎn)考慮播放服務(wù)器的解碼部分。同樣先打開(kāi)drm_errorsummary.log，可以發(fā)現(xiàn)日志里出現(xiàn)了大量從kernel.log收集到的解碼錯(cuò)誤 （Decoders Crashed）如圖6所示。

圖6 Kernel日志

圖7 odeticsd日志

其次，查看odestic.log 日志，發(fā)現(xiàn)負(fù)責(zé)解碼dolphin子系統(tǒng)有連接超時(shí)和傳輸數(shù)據(jù)的錯(cuò)誤，進(jìn)一步證實(shí)了故障源于解碼部分，即媒體模塊IMB 板。另外，odestic.log日志完整記錄每場(chǎng)電影播放的事件，對(duì)于偶發(fā)性故障，應(yīng)在日志中重點(diǎn)檢查影院所反饋的故障時(shí)間點(diǎn)，從而有效地縮小檢索范圍，準(zhǔn)確定位故障。如圖7所示。

因此，可以刷新或升級(jí)媒體模塊的固件來(lái)進(jìn)一步觀察故障是否解決，如故障仍然存在，需更換IMB板塊。

案例3：Show Vault播放服務(wù)器無(wú)法正常播放節(jié)目，顯示不能加載播放列表

通常此類故障，在圖像化界面提示的信息較少，且涉及到的故障可能較多，很難快速做出判斷，日志分析是一個(gè)很好的手段。

首先，打開(kāi)drm _errorsummary.log，發(fā)現(xiàn)安全管理器SM 的版本顯示為丟失，根據(jù)DCI規(guī)范，當(dāng)播放服務(wù)器的SMS子系統(tǒng)無(wú)法與安全管理器SM連接的情況下，是無(wú)法加載播放列表和播放電影。如圖8所示。

圖8 服務(wù)器型號(hào)和版本信息

其次，逐一檢查與加載播放列表有關(guān)的日志文件odestc.log 和drmplaylistd.log 這兩個(gè)日志。發(fā)現(xiàn)這兩個(gè)日志中都存在相關(guān)錯(cuò)誤，特別是在drmplaylistd.log中更為明顯，顯示播放服務(wù)器反復(fù)啟動(dòng)卻始終無(wú)法連接到安全管理器。如圖9所示。

圖9 drmplaylistd日志

因此，故障解決的思路是檢查IMB板與放映機(jī)之間的網(wǎng)絡(luò)通信，應(yīng)通過(guò)排查網(wǎng)絡(luò)中的設(shè)備，包括網(wǎng)線、交換機(jī)、放映機(jī)的控制板及IMB板來(lái)定位故障。

通過(guò)以上案例分析，可以看出日志分析絕非易事，它不僅需要有良好的英語(yǔ)基礎(chǔ)，而且要對(duì)設(shè)備的工作原理和各個(gè)子系統(tǒng)熟練掌握，才能成功地在大量的數(shù)據(jù)中找到線索，并結(jié)合對(duì)設(shè)備的硬件和軟件的理解，最終定位故障。

總而言之，日志分析應(yīng)遵循從易到難，簡(jiǎn)單的可通過(guò)關(guān)鍵詞搜索，復(fù)雜的情況需根據(jù)故障發(fā)生的時(shí)間點(diǎn)，反復(fù)對(duì)比不同的日志，從而找到有價(jià)值的線索和關(guān)鍵突破點(diǎn)。希望通過(guò)此文能拋磚引玉，提供對(duì)播放服務(wù)器日志分析的思路和方法，幫助影院技術(shù)人員從中收獲啟發(fā)，并舉一反三，掌握好這個(gè)故障診斷的利器。

注釋

①杜比公司于2014年收購(gòu)Doremi公司并延用Doremi的核心技術(shù)，本文提到的Show Vault服務(wù)器現(xiàn)為杜比公司所有。

② 杜 比 日 志 在 線 分 析 網(wǎng) 站 www.http ：//loganalyzer.dolbycustomer.com/，用戶可上傳日志文件做在線分析。

③S.M.A.R.T.全稱為 “Self-Monitoring Analysis and Reporting Technology”，即 “自我監(jiān)測(cè)、分析及報(bào)告技術(shù)”，是一種自動(dòng)的硬盤(pán)狀態(tài)檢測(cè)與預(yù)警系統(tǒng)和規(guī)范。