続報: microSD カードの寿命を調べる

５日位で勝負がつくかもしれないと思って始めた実験だが、２か月近く経った今ようやく先が見えてきた。

2015/2/21 23時追記あり。

/*-----------  -----------*/

最新状況

グラフ上に丸い点を打っているのがファイルを読んで書き込んだ内容と不一致が検出された場合を表している。磁気研究所（MAG-LAB）のサンプルのプロット（赤）の終わりの方に点が集中しているのが分かると思う。しかしプロットの線が途中で大きく落ち込んだことが目を引くので、そのことから触れることにしよう。

空きスペース不足

前半でプロットが威勢よく右肩上がりになっていたのは microSD カード上のルートファイルシステムの空き容量が少なくなることが主な原因だったらしい。磁気研究所のサンプルは書き込み量が 4T バイトを超えるあたりからプロットが急上昇し、頻繁に Linux がフリーズするようになったのでいよいよ終わりが見えたか、と思ったのだが間違いだった。

嫌な予感がして df コマンドで調べたら、ファイルシステムの空きが 6.6M バイトまで減少している事が分かった。

volumio@volumio220:~$ df -h
Filesystem      Size  Used Avail Use% Mounted on
rootfs          1.8G  1.7G  6.6M 100% /
/dev/root       1.8G  1.7G  6.6M 100% /
devtmpfs        248M     0  248M   0% /dev
tmpfs            50M  516K   50M   2% /run
tmpfs           5.0M     0  5.0M   0% /run/lock
tmpfs           512M     0  512M   0% /run/shm
Ramdisk         512M     0  512M   0% /run/shm

4G バイトの micorSD に 2G バイト用の Volumio イメージを書き込んでテストを始めた時 150M バイト程度の空きだった。決して多くは無いが、ログは全てローテートされているから問題ないと考えルート区画のサイズは変更せずにテストを進めていたのだ。調べると「ログは全てローテートされている」と言う思い込みが間違いの元だったことが分かった。

volumio@volumio220:/var/log$ ls -l
total 133140
（中略）
-rw-rw-r-- 1 root        utmp     135851136 Feb  3 14:07 wtmp

/var/log/wtmp はログイン履歴の記録だ。これはディフォルトでローテートされるようになっていない事を見落としていた。ログイン履歴を管理しないのでこのログが出ないようにしてしまっても構わなかったが、ほかにも似たようなことがあるかもしれないのでルート区画を microSD の容量いっぱいまで拡張した。そのためプロットに不連続が生じたという次第。お粗末でした（汗）。

この後しばらく順調に推移したので、空きスペース不足が原因の問題だったと考えて間違いないだろう。

比較エラーの状況

比較で不一致が検出されるようになった部分を拡大した。

書き込み量が 8T バイトに達する少し手前で１回不一致が検出されているが、その後 1T バイト程度は何事もなく推移している。しかしその先で不一致が頻発するようになり、今では１セット 1G バイトの書き込み x ５で毎回不一致が検出されるようになっている。Transcend のプロット（緑）にも不一致が出始めたが、今のところ小康状態の様だ。

磁気研究所のサンプルでは Linux のファイルも壊れてきているようで、起動時の「Waiting for /dev to be fully populated...」で長い時間待たされた挙句に alsactl の起動に失敗したり、 sudo が使えなくなったりしている。

volumio@volumio220:~$ sudo ls /
Illegal instruction
volumio@volumio220:~$ su
Password: 
root@volumio220:/home/volumio# ls /
bin   dev  home  lib64  mnt2  proc  run   selinux  sys  usr
boot  etc  lib   mnt    opt   root  sbin  srv      tmp  var
root@volumio220:/home/volumio# exit
exit
volumio@volumio220:~$

su を使えばやりたいことができているのでテストを継続しているが、もう終わりにしても良い状況なのかもしれない。

2015/2/21 23時 追記:
この記事を書いてほんの数時間したらテストを継続できない状態になってしまった。テストプログラムを動かしている Python を起動しようとすると Segmentation fault が起こるようになってしまったのだ。

volumio@volumio220:~$ python
Segmentation fault
volumio@volumio220:~$ su
Password: 
root@volumio220:/home/volumio# python
Segmentation fault
root@volumio220:/home/volumio#

こうなると一巻の終わり。総書き込み量 9.3T バイトである。どんな状態になっているのか調べるために SDフォーマッター 4.0 (https://www.sdcard.org/jp/downloads/formatter_4/) で上書きフォーマットを行ったら全く問題なくできてしまった。試しに 6M バイトほどファイルをコピーして比較してみたが不一致は無い。常識的には正常と言うべき状態だ。しかし今までやってきたことを考えると、とてもそうは思えない。

もっと詳しく調べて、改めて別の記事にしたいと思う。

もう少し詳しいデータ

区画を拡張したのと同じタイミングで１回の書き込みと読出し処理の時間を別々に測れるようにしてみた。

ここで目を引くのが、磁気研究所のサンプルの読出し時間が著しい増加傾向を示している事だ。現状では読出しの方が書き込みより時間がかかる状況が頻発しているが、他のサンプルではこのような状況は発生していない。

読出しデータの不一致が発生する以前から一貫して同じ傾向を示しているので、寿命が尽きかけたことの表れではなく、このサンプルの個性なのだろう。磁気研究所のこの製品共通の特徴である可能性が高いが、１つしか試していないので断言することはできない。

書き込み量モニタリングに不都合な真実

今回書き込み量を把握するのに dumpe2fs と iostat コマンドを使っている。実際の運用時のモニタリングにも使えないか試す目的もある。

前回の記事に Linux が異常終了した時 dumpe2fs が表示する Lifetime 値が更新されない、と言う問題があることを書いたが、これ以外にも困った現象が見つかってしまった。

Mon Feb  9 20:08:19 JST 2015
mmcblk0          77.28         0.80         3.99     418270    2090545
Mon Feb  9 20:08:19 JST 2015
Check OK!
## I/O time: operation total max min
#WRT_256k  56.1   2.161   0.004
#WRT_256M 160.6  54.090  52.587
#RD_256k   54.4   2.015   0.049
#RD_256M  141.9  47.444  47.012
Mon Feb  9 20:30:40 JST 2015
mmcblk0          77.27         0.80         3.99     419298    2095678
Mon Feb  9 20:30:40 JST 2015
Check OK!
## I/O time: operation total max min
#WRT_256k  52.9   2.314   0.004
#WRT_256M 164.6  55.750  53.982
#RD_256k   53.6   2.017   0.049
#RD_256M  142.4  47.460  47.448
Mon Feb  9 20:52:30 JST 2015
mmcblk0          77.27         0.80         0.01     420325       3659
Mon Feb  9 20:52:30 JST 2015
Check OK!
## I/O time: operation total max min
#WRT_256k  52.5   1.956   0.003
#WRT_256M 163.8  55.133  53.830
#RD_256k   53.8   1.865   0.049
#RD_256M  142.1  47.657  47.017
Mon Feb  9 21:14:49 JST 2015
mmcblk0          77.27         0.80         0.02     421352       8792

これは実際のテスト用スクリプトが吐き出すログの抜粋で、「mmcblk0」で始まる行が「iostat -m | grep mmcblk0 | tee -a $log」の結果だ。つまり行の末尾の数字が Linux が起動して以来のメガバイト単位の書き込みデータ量なのだが、2095678の次が3659に減ってしまっている。

これは推測だが、ディスク I/O の最小ブロックサイズである512バイト単位の値が 2³²-1 を超えるとゼロに戻ってしまうらしい。つまり 3659 = 2095678 + 5132 - {512 x (2³²-1) / 1024 / 1024} ではないか、と言うこと。

(2³²-1) は符号無し32ビット整数の最大値だ。同様の現象が「dumpe2fs -h」の結果にも見られるので、kernel が管理している512 バイトブロック数単位の I/O カウンターがオーバーフローしているからではないかと推定している。

今回のように継続的にログを取っていればこのような増えることはあっても減ることのない値のおかしな挙動は簡単に見つかるし、補正も可能である。確か iostat コマンドを含む sysstat パッケージはログを作成して継続的な監視を行うよう設定できたはずだ。こうすれば iostat または sar コマンドなどでもカウンターのオーバーフローへの対策が取れているのかもしれない。そうでないとサーバーで使うときに困るはずだ。これを調べるのは宿題にしよう。

今回のまとめ

テストを開始して２か月してようやく終わりが見えた。と言ってもまだ 1/4 だが。

磁気研究所のサンプルはもう少しテストを続けて、最後にどうなるか見届けたいと思う。Linux がフリーズして、再起動を試みても一部のファイルが壊れていて起動しない、と言うシナリオになるだろうと予測しているが、もしかすると思いもつかない現象があるかもしれないからね。

これまでの結果から microSD にその容量の 2,000 倍のデータを書き込んでも大丈夫、と言う感触が得られた。これは容量 4GB だとひたすら書き込みを続けて２ヶ月かかった作業だ。普通の使い方なら少なくとも１年間の連続稼働に匹敵するのではないかと思う。単純計算で容量 16GB なら ４年以上 OK と言うことになる。microSD 故に寿命が心配、と言うのは杞憂だろう。