Linux 的 udev 是個有趣又有用的玩具（2）

在上一個單元，我們已經建立起一個機制（mechanism），這包含一個所有 uevent 的萬能勾（universal hook），也就是 /etc/udev/rules.d/z99_test.rules，以及讓這個勾勾直接跳過來執行（execute）、放在家裡面（HOME）的一個叫做 my_script 的程式。也就是：

$ cat /etc/udev/rules.d/z99_test.rules
RUN+="/home/nobody/my_script"
$ ls -l ~/my_script
-rwxr-xr-x 1 nobody nobody 1056 Nov 22 03:04 /home/nobody/my_script

因為這個程式執行的時候並沒有 tty，也就是說，它不能夠打印出任何我們看得到的訊息（messages），所以我們就用 aplay(1) 來播放一個簡短的聲音檔，來通知（notify）我們這個程式的執行狀況，例如，到底有沒有被執行到、被執行了幾次，或是在什麼情況下會被執行。但是為了寫一個有用的程式，我們終究必須要讓這個程式印出可以看得到的訊息，以便監控程式發展過程的任何問題。

所以在這個單元，我們就必須要先建立好程式發展環境，讓我們可以鉅細靡遺地監控這個程式的執行細節，也讓我們可以 debug 寫程式時無法迴避的許多錯誤。沒有 tty 怎麼辦呢？一個簡單的辦法就是讓 my_script 這個程式把所有的訊息輸出到一個 logfile，例如：

#!/bin/sh
LOGFILE=/tmp/my_script.log
aplay /usr/share/sounds/KDE_Beep_Bottles.wav
date >> $LOGFILE

這裡 ">>" 的意思，就是把 date 這個指令所產生的 stdout 都附加（append） 到 $LOGFILE 裡。但是 ">>" 並不包括 stderr。所以萬一系統找不到 date(1) 這個程式的話，例如，你把 "date" 錯打成 "data"，在 $LOGFILE 裡還是看不到像是

bash: data: command not found

的錯誤訊息，因為，像上列這種錯誤訊息，通常是輸出到 stderr，而 ">>" 只 redirect 了 stdout。

我們現在就先檢查一下，到底 $LOGFILE 有沒有真的被產生出來、檔案屬性如何、檔案裡面到底有沒有東西：

$ ls -l /tmp/my_script.log
-rw-r--r-- 1 root root 348 Nov 4 22:10 /tmp/my_script.log
$ less /tmp/my_script.log

請注意，它所有權屬於 root，這一點很重要，因為，雖然我們的程式 my_script 屬於一個一般的使用者（user permission），例如 "nobody"，然而它是由 udev 系統叫出來執行的，所以這個 process 也跟著具有 root 的權限（permission），而其所產生的檔案，自然也具有 root 的預設權限 644。我們可以再看一次 my_script 這個檔案的屬性：

$ ls -l ~/my_script
-rwxr-xr-x 1 nobody nobody 188 Nov 4 22:23 my_script

接下來，為了可以在 $LOGFILE 裡記錄下來這個程式所產生的所有錯誤訊息（error messages），我們在下一個範例，故意漏打 "sounds" 的 "s"，讓 aplay 找不到這個聲音檔，而發出送到 stderr 的錯誤訊息。同時，在這一行最後面加上 "2>> $LOGFILE"。這個意思是說，把所有的 stderr 重新導向（redirect），並附加（append）到 $LOGFILE 這個檔案裡。

#!/bin/sh
LOGFILE=/tmp/my_script.log
aplay /usr/share/sound/KDE_Beep_Bottles.wav 2>> $LOGFILE
date >> $LOGFILE

修改好以上的 my_script 並儲存好新版之後，再插上或拔除任何一個 usb 隨身碟，就應該可以在 $LOGFILE 裡邊找到 aplay(1) 那一行所產生的錯誤訊息。因為這一行執行有誤（syntax error），所以這一次我們聽不到任何聲響。

為了避免必須在每一個指令後面都必須加上 ">> $LOGFILE" 或是 "2>> $LOGFILE"，我們要介紹一個一勞永逸的方法，來把這個程式所產生的所有 stdout 以及 stderr 都 redirect 到 $LOGFILE 裡。修改 my_script 成為：

#!/bin/sh
LOGFILE=/tmp/my_script.log
exec 3>> $LOGFILE && exec >& 3 && exec 2>&1
aplay /usr/share/sounds/KDE_Beep_Bottles.wav
date 

以上新版 my_script 的第 3 行，會把從第四行開始，所產生的所有 stdout 以及 stderr 都重新導向（redirect），並附加（append）到 $LOGFILE 裡去。自然，這一行必須放在所有可能會輸出文字的指令之前。

我們很快地就會發現，logfile 裡面所記錄的資料，在先後順序有一點混亂（scrumbled order）。這是因為 uevent 是很頻繁（frequent）發生的事件，而每一次的 uevent 都會觸發 my_script 的執行，所以常常同一個時間（concurrently）會有 my_script 的許多分身（processes）同時、但不同步地（asynchronously）在執行，而它們都正在寫入這個 logfile，彼此之間會形成一種競爭（competitive）的態勢，導致所寫入資訊的前後順序交錯（disorder），以至於看起來好像並沒有按照 my_script 裡的執行順序輸出。其實，順序交錯的輸出是導因於 my_script 的許多不同分身，以非同步的競爭狀況交錯寫入的結果。因此，udev 系統每次呼叫我們的 my_script 時，都會設定一個環境變數 SEQNUM 來顯示該事件（uevent）的產生順序。事實上，udev 系統執行 my_script 時，會設定更多對有用的變數（defined variables）。這可以用 udevmonitor(8) 加上 --env 的選項來監看。

有了以上的理解之後，讀者就可以更順利地運用 logfile 來監視這個程式的執行狀況，以便於 debug 許多程式設計過程中無法避免的錯誤，而免於盲目揣測。

在下個單元，我們就可以開始來限縮（restrict）這個程式，讓它只對少數篩選（filter）出的事件（uevent）作出反應（response）。然而，讀者現在已經具有起碼的基礎，可以先行嘗試做一些實驗，例如嘗試在 my_script 裡呼叫 xeyes，讓電腦每碰到一個 udev 事件，就跳出兩隻眼睛，來取代聲音檔的播放。但是也很快就會察覺，事情沒那麼單純。這是因為撰寫這種程式確有其詭異（tricky）之處。詭異之處不只在於這個環境下沒有 tty，使得所有的 stdout 跟 stderr 都無路可走，還有「無家可歸」（HOME，USER, 等環境變數都沒有設定），也沒有 locale 變數（LANG, LC_CTYPE, 等變數都沒有設定）...。不過也不用擔心，因為我們已經介紹了讓讀者可以完整抓到錯誤訊息的方法。

上一個單元：Linux 的 udev 是個有趣又有用的玩具（1）
下一個單元：Linux 的 udev 是個有趣又有用的玩具（3）