はじめに
前回の記事の続きです。
このような調査が必要になった経緯を知りたい方は、前回のページを見てください。
犯行現場 - 奇怪な証拠を残す容疑者
前回の記事では、Linuxを使って疑似USBメモリを作り、機器Aからファイルが書き込まれたファイルを収集サーバに送付する仕掛けを検討しました。
A~Cの3方式を考案して実験し、性能面で優れるinotify APIを使った方式Cを採用しました。
方式Cを使った動作テストのために、機器Aの代わりにWindows 10のPCを繋いでテストしていました。安定して読み書きができるか確認するため、大き目のmpegファイルを疑似USBメモリ上に複数コピーし、疑似USBメモリ上のmpegファイルを動画再生ソフトで問題なく再生できるかを確認していました。
ある日、動画再生テストをしている途中に、方式Cの処理を実行し忘れた事に気付きました。実行開始すると、奇妙な現象が起きました。
- Windows PCから疑似USBメモリ上にファイルを開いて読むと、inotifywaitでMODIFYイベントが起きる
- すぐに同じファイルをもう一度開いて読むと、MODIFYイベントが起きない
- 別のファイルを開いて読むと、最初の1回はMODIFYイベントが起き、2回目以降は起きない
ファイルを開くと、最初の1回だけMODIFYイベントが出ます。
ファイルの最終アクセス日時が更新されたためかと思いましたが、そうだとすれば2回目のアクセス時にもMODIFYイベントが起きるはずです。でも起きません。
幸い、この奇妙な動作が起きても、新規ファイルを収集サーバに送付する仕掛け自体には影響ありません。その日は調査を諦めました。
翌日再度試してみると、なんと昨日MODIFYイベントが出なくなったファイルでMODIFYイベントが出ました。2回目からは出ません。別のファイルで試しても同様です。
動作に支障は無いとはいえ、原因不明の挙動が起きる機器を本番で使いたくはありません。
容疑者を探しに行きましょう。
潜入捜査 - WiresharkによるUSBパケットキャプチャ
一体何を書き込んでいるのか調べるために、Windows PCにWiresharkをインストールして、USBパケットをキャプチャしました。書き込みしているのであれば、SCSI Writeコマンドが出ているはずです。
挙動が良くわかるよう、疑似USBメモリを綺麗な環境にしてから調査しました。
- 疑似USBメモリをFAT32でフォーマット
- mpeg形式の動画を用意。
- 1.mpg, 2.mpg, ... のように、ファイル名を変えつつUSBメモリ上にmpeg動画を複数コピー
- 日が変わるのを待つ
- Wiresharkを起動。疑似USBメモリを挿したUSBポートを監視
- 動作再生ソフトで、疑似USBメモリ上の mpeg を再生
- Wiresharkで、SCSI Writeコマンドを探す
- Writeしたデータを探す
USBメモリの、0x6000(=24576)セクタから8セクタ分書き込みしています。
中を見ると、1.mpgや、2.mpg等のファイル名が見えます。どうやら書き込んでいるのは、ディレクトリエントリ(Explorerで見えるファイル一覧)のようです。
違うファイルを再生して試しても、同じ0x6000からのデータを書き換えている事がわかりました。
科学捜査 - どう書き換えているか調べる
では一体、何から何に書き換えているのでしょうか。mpeg再生前後で比べてみましょう。
mpeg再生前に、機器B上でディレクトリエントリの情報を保存しておき、再生後と比べます
$ printf "%d\n" 0x6000
24576
$ sudo dd if=/dev/mmcblk2p9 of=before skip=24576 count=8
ここでWindows上で2.mpgを動画再生
$ sudo dd if=/dev/mmcblk2p9 of=after skip=24576 count=8
$ hexdump -C before > before.txt
$ hexdump -C after > after.txt
$ diff -u before.txt after.txt
--- before.txt 2020-08-25 05:38:20.931494077 +0000
+++ after.txt 2020-08-25 05:40:56.488613081 +0000
@@ -5,7 +5,7 @@
00000040 53 59 53 54 45 4d 7e 31 20 20 20 16 00 42 94 86 |SYSTEM~1 ..B..|
00000050 16 51 16 51 00 00 95 86 16 51 03 00 00 00 00 00 |.Q.Q.....Q......|
00000060 31 20 20 20 20 20 20 20 4d 50 47 20 10 6d 9c 86 |1 MPG .m..|
-00000070 16 51 18 51 00 00 00 9b dc 50 06 00 00 90 f0 0d |.Q.Q.....P......|
+00000070 16 51 19 51 00 00 00 9b dc 50 06 00 00 90 f0 0d |.Q.Q.....P......|
00000080 32 20 20 20 20 20 20 20 4d 50 47 20 10 66 ac 86 |2 MPG .f..|
00000090 16 51 18 51 00 00 00 9b dc 50 8b 6f 00 90 f0 0d |.Q.Q.....P.o....|
000000a0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
データを見ると、ディレクトリエントリは、32バイトが1ファイル分のようです。
2.mpgの先頭から0x12バイト目が、0x18から0x19に書き換わっていました。
この値は何でしょうか? wikipediaで調べてみるとLast Access Date、つまり最後にファイルにアクセスした年月日のようです。
https://en.wikipedia.org/wiki/Design_of_the_FAT_file_system#Directory_entry
確かに、0x18=24、0x19=25、昨日は24日、今日は25日です。
不良ではなく仕様でした。容疑者は罪を犯していなかったのです。
書き換えていたのは最終アクセス「日」だとわかりました。最終アクセス「日時」ではなく、時刻を含まない年月日までの情報でした。
その日初めてファイルを参照するとMODIFYイベントが起き、その後は同じ日に同じファイルを参照しても、MODIFYイベントが起きない理由がわかりました。
現場検証 - 嫌疑の晴れた容疑者と一緒に
Wikipediaは誰でも編集できてしまうので、内容の信頼性が低いです。本当にこれがアクセス日時なのか、より信頼性の高い情報を使って確認しましょう。
LinuxはFAT32のファイルシステムを読み書きできます。LinuxカーネルソースのFAT32の処理を見れば、わかりそうです。
機器Bで使っているLinux kernelは4.4.194です。FAT32の処理で、最終アクセス日(atime)を処理する箇所を抜粋して見てみましょう。
ディレクトリエントリのデータ構造
kernel/include/uapi/linux/msdos_fs.h
#define MSDOS_NAME 11 /* maximum name length */
struct msdos_dir_entry {
__u8 name[MSDOS_NAME];/* name and extension */
__u8 attr; /* attribute bits */
__u8 lcase; /* Case for base and extension */
__u8 ctime_cs; /* Creation time, centiseconds (0-199) */
__le16 ctime; /* Creation time */
__le16 cdate; /* Creation date */
__le16 adate; /* Last access date */ // 最終アクセス年月日
__le16 starthi; /* High 16 bits of cluster in FAT32 */
__le16 time,date,start;/* time, date and first cluster */
__le32 size; /* file size (in bytes) */
};
ディレクトリエントリの1ファイルのデータ構造です。__u8が1バイト、__le16が2バイトです。32バイトで1ファイル分です。
offset 0x12から2バイトが最終アクセス年月日です。
前述した差分データでは、0x19 0x51 がそれに当たります。
アクセス日の更新処理
linux/fs/fat/inode.c: 最終アクセス日を更新
void fat_time_unix2fat(struct msdos_sb_info *sbi, struct timespec *ts,
__le16 *time, __le16 *date, u8 *time_cs)
{
// 一部略
fat_time_unix2fat(sbi, &inode->i_atime, &atime,
&raw_entry->adate, NULL);
linux/fs/fat/misc.c: unix timeから、年月日の2byteに変換。
void fat_time_unix2fat(struct msdos_sb_info *sbi, struct timespec *ts,
__le16 *time, __le16 *date, u8 *time_cs)
{
// 一部略
/* from 1900 -> from 1980 */
tm.tm_year -= 80;
/* 0~11 -> 1~12 */
tm.tm_mon++;
*date = cpu_to_le16(tm.tm_year << 9 | tm.tm_mon << 5 | tm.tm_mday);
上の処理をもとに、0x19 0x51を日付に変換してみます。
2020/8/25 になりました。これはファイルを読んだ日です。どうやらアクセス日時で合っているようです。容疑者を釈放しましょう。
証拠は目の前にあった
実は、Explorer上でUSBメモリ上のmpegファイルのプロパティを開くと、アクセス日時が見えます。
日付だけで、時刻が無い事もわかります。
最初からこれを見ておけば原因がわかったのでした。
使用ツール
- Wireshark https://www.wireshark.org/download.html
商標
- Windowsは,米国Microsoft Corporationの米国およびその他の国における登録商標または商標です
- Linuxは、Linus Torvalds氏の日本およびその他の国における登録商標または商標です。
- Wiresharkは、WIRESHARK FOUNDATION, INC.の米国およびその他の国における登録商標または商標です
- 記載の会社名、製品名、サービス名等はそれぞれの会社の商標または登録商標です。