aptpod Advent Calendar 2022７日目の記事を担当する、intdashグループの落合です。
いきなりですが、あなたは今年はどんなバグの調査をしましたか？
解決に時間がかかったもの、あっさり解決できたもの色々あったかもしれませんね。
私も問い合わせの度に調査してきました。バグだった場合もそうじゃなかった場合もありますが、調査は早く終わらせたいですよね。
この記事では、問題が出た時に早期解決できるように、ありがちな原因と確認コマンドをまとめてみます。 ただし、
- IoTデバイスでLinuxが稼働しておりネットワークやUSBで通信するシステム
を前提として、そのシステムの状態によって起こるアプリケーションの問題をまとめます。
チートシート
| 現象例 | 原因 | 調査方法 |
|---|---|---|
| ファイル保存でエラー | 空き容量不足 | df -h <確認したいディレクトリ> |
| プロセスがOSに落とされる メモリ確保でエラー |
メモリ不足 | dmesg -T | grep '[kK]ill process'vmstat 1 -a |
| ファイルオープンでエラー | ファイルディスクリプタ不足 | ls /proc/$(pidof <プロセス名>)/fd' |
| デバイスと通信できない | USB未接続 | dmesg -T | grep disconnect |
| ネットワーク通信できない | モバイル回線未接続 | ping -c 1 <対象サーバー> |
原因ごとの解説
空き容量不足
ファイルのフラッシュ時に空き容量が足りない場合エラーになります。
例
以下のコマンドでは
- C言語（久しぶりに書いた！）でファイルを作成をするコードをmain.cとして保存
- gccでコンパイル
を行います。
$ cat << EOF >main.c
#include <errno.h>
#include <stdio.h>
#include <string.h>
const char* contents = "C lang! It’s been a while.";
int main(int argc, const char* argv[]) {
// File open
FILE* f = fopen(argv[1], "w");
if (f == 0) {
fprintf(stderr, "fopen() failed: %s (%d)\n", strerror(errno), errno);
return 1;
}
// File write
size_t len = fwrite(contents, 1, strlen(contents), f);
if (len != strlen(contents)) {
fprintf(stderr, "fwrite() failed: %s (%d)\n", strerror(errno), errno);
return 1;
}
// File close
if (fclose(f) != 0) {
fprintf(stderr, "fclose() failed: %s (%d)\n", strerror(errno), errno);
return 1;
}
return 0;
}
EOF
$ gcc main.c -o nospace-test
コンパイルしたプログラムを空き容量が無いディレクトリ（以下の例では/tmp）に対して実行すると、fclose()のタイミングでエラーになります。
$ ./nospace-test /tmp/test fclose() failed: No space left on device (28)
fwrite()のタイミングではなくfclose()でエラーににあるため、fclose()のエラーをハンドルしていないと気がつかないかもしれません。
フラッシュのタイミングでエラーになるので、fflush()を呼ぶ場合はそのタイミングでエラーになります。
調査方法
dfコマンドのAvailで空き容量を確認できます。
df -h <確認したいディレクトリ>
$ df -h /tmp/test Filesystem Size Used Avail Use% Mounted on tmpfs 1.9G 1.9G 0 100% /tmp
メモリ不足
メモリ不足によりメモリの動的確保がエラーになります。または、OOM Killerによってプロセスがkillされます。
例
以下のコマンドでは、
- C言語でメモリ確保を繰り返すコードをmain.cとして保存
- gccでコンパイル
を行います。
$ cat << EOF >main.c
#include <stdlib.h>
int main(int argc, const char* argv[]) {
while (1) {
void* leaked = malloc(1024*1024); // 1MB
}
return 0;
}
EOF
$ gcc main.c -o nomem-test
コンパイルしたプログラムを実行するとOOM Killerによりkillされます。
$ ./nomem-test Killed
調査方法
OOM Killerが実行されたことはログに残るためdmesgを検索することで確認できます。
dmesg -T | grep '[kK]ill process'
$ dmesg -T | grep '[kK]ill process' [Mon Dec 5 07:30:05 2022] Out of memory: Kill process 269571 (nomem-test) score 350 or sacrifice child
それとは別に、メモリリークしていることを確認したい場合は vmstat 1 -a で active の増加度合いで確認できます。
$ vmstat 1 -a & ./nomem-test [1] 288948 procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu----- r b swpd free inact active si so bi bo in cs us sy id wa st 1 0 0 1416648 2054456 252476 0 0 17 3 63 96 1 1 98 0 0 2 0 0 741920 2054472 700860 0 0 0 48 594 469 6 11 83 0 0 2 0 0 87432 2042036 1199888 0 0 36 24 640 522 7 11 81 0 0 Killed $ kill 288948
余談ですが弊社のintdash Edge Agentはvmstatを含むメトリクス情報をサーバーに送信するサンプル設定が入っています。以下はそのデータの一部を可視化したものです。
ファイルディスクリプタ不足
１つのプロセスで使用するファイルディスクリプタが上限に達すると、新しいファイルを開くとエラーになります。
例
以下のコマンドでは
- C言語でファイルを繰り返し作成するコードをmain.cとして保存
- gccでコンパイル
を行います
$ cat << EOF >main.c
#include <errno.h>
#include <stdio.h>
#include <string.h>
int main(int argc, const char* argv[]) {
char path[256];
for (int i = 0; i < 1024 * 1024; i++) {
sprintf(path, "/tmp/%d", i);
FILE* f = fopen(path, "w");
if (f == 0) {
fprintf(stderr, "fopen() failed: %s (%d)\n", strerror(errno), errno);
return 1;
}
}
return 0;
}
EOF
$ gcc main.c -o nodescriptor-test
コンパイルしたプログラムを実行すると、ファイルディスクリプタが枯渇しfopen()がエラーになります。
$ ./nodescriptor-test fopen() failed: Too many open files (24)
調査方法
特定のプロセスが開いているディスクリプタ番号が列挙されます。
ls /proc/$(pidof <プロセス名>)/fd'
$ ls /proc/$(pidof nodescriptor-test)/fd 0 1 10 11 12 2 3 4 5 6 7 8 9
ファイルディスクリプタ数の上限はulimit -nで確認できます。
$ ulimit -n 1024
USB未接続
USBデバイスが認識されておらず通信ができない。
物理的な切断も含めLinux OSがUSBデバイスを認識しなくなると（当たり前ですが）デバイスとの通信はできなくなります。
調査方法
USBの接続/切断はログに出力されているため、ログを検索することで確認できます。
dmesg -T | grep disconnect
$ dmesg -T | grep disconnect [Mon Dec 5 08:39:10 2022] usb 1-2.4: USB disconnect, device number 3
このままだと、どのデバイスかわかりにくいので、<bus>-<port[.port[.port]]> を検索すると、そのUSBデバイスが接続した時のUSBディスクリプタの情報を確認できます。
$ dmesg -T | grep 1-2.4 [Mon Dec 5 08:38:02 2022] usb 1-2.4: new high-speed USB device number 3 using tegra-xusb [Mon Dec 5 08:38:02 2022] usb 1-2.4: New USB device found, idVendor=2560, idProduct=c123 [Mon Dec 5 08:38:02 2022] usb 1-2.4: New USB device strings: Mfr=1, Product=2, SerialNumber=0 [Mon Dec 5 08:38:02 2022] usb 1-2.4: Product: e-CAM22_USB [Mon Dec 5 08:38:02 2022] usb 1-2.4: Manufacturer: e-con Systems [Mon Dec 5 08:38:02 2022] uvcvideo 1-2.4:1.0: Entity type for entity Processing 2 was not initialized! [Mon Dec 5 08:38:02 2022] uvcvideo 1-2.4:1.0: Entity type for entity Extension 3 was not initialized! [Mon Dec 5 08:38:02 2022] uvcvideo 1-2.4:1.0: Entity type for entity Camera 1 was not initialized! [Mon Dec 5 08:38:02 2022] input: e-CAM22_USB as /devices/3530000.xhci/usb1/1-2/1-2.4/1-2.4:1.0/input/input4 [Mon Dec 5 08:38:04 2022] usb 1-2.4: usb_suspend_both: status 0 [Mon Dec 5 08:39:10 2022] usb 1-2.4: USB disconnect, device number 3
モバイル回線未接続
モバイル回線が接続していない（電波が悪い）ため、通信ができない、通信遅延が大きい。
これも当たり前ですが、電波が悪ければ通信はできません。
調査方法
pingで対象のサーバーまでの接続とRTTを確認できます。
電波状況をModemManagerやATコマンドなどで確認することもできますが、過去に「電波は十分だけどアプリはネットワークに繋がらない」といったケースがあり、これは名前解決ができていなかったことが原因でした。 そのためアプリケーションと同じ状況を確認するという意味でも、まずpingを確認するのが良いと思っています。
ping -c 1 <対象サーバー>
（サーバーはpingに応答する必要があるため、ICMPに対応している必要があります）
$ ping -c 1 google.com PING google.com(nrt12s36-in-x0e.1e100.net (2404:6800:4004:822::200e)) 56 data bytes 64 bytes from nrt12s36-in-x0e.1e100.net (2404:6800:4004:822::200e): icmp_seq=1 ttl=56 time=7.60 ms --- google.com ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 7.595/7.595/7.595/0.000 ms
time=7.60 ms がRTTになります。
またまた余談ですが、intdash Edge AgentがインストールされたIoTデバイスを、車に乗せて走行した時のpingを含むネットワークのメトリクスはを可視化した例です。
おわりに
この記事の冒頭では、「問題が起きる」→「調べる」という流れを書いていますが、効率が良いのは、「状態を監視」→「問題を未然に防ぐ」の方ですね。
記事の途中でも記載したように、intdash Edge Agentを使用して、サーバーに送信することですることで、状態を可視化することも可能です。ご興味がありましたら是非お試しください！
