fukasawa
2020年8月13日 19時14分
いつもお世話になっております。
Armadillo-640にてAWL13を有効にする`ifup awlan0`とアプリケーションが一時的に停止されてしまいます。
原因・対処方法わかりますでしょうか。
Armadillo-640にAWL13を接続しています。
Linux起動時に非同期でネットワークの起動と自作のアプリケーションを開始しています。
アプリケーションでは主にUART2・UART5とのデータの送受信を行い、標準出力(UART3)に1秒に1回現在の状態をprintしています。
このとき、最初は問題なく動作しますが、1分過ぎたあたりで、AWL13が有効になったせいか10秒ほどアプリケーションが停止しています。
Teratermで記録したログを抜粋して変更したものが以下です。全体を添付します。
1:14~1:26と1:26~1:38の間でフリーズしています。
... [0 00:01:12.0234] meas, 0057.000, F, F,,, [0 00:01:13.0234] meas, 0058.000, F, F,,, [0 00:01:13.0906] No DHCPOFFERS received. [0 00:01:13.0906] No working leases in persistent database - sleeping. [0 00:01:14.0234] meas, 0059.000, F, F,,, [0 00:01:14.0609] [ 72.173286] awl13: WID_STATUS CODE=0 (DISCONNECTED) [0 00:01:14.0625] [ 72.178192] awl13: disconnected! [0 00:01:14.0625] [ 72.181637] awl13: WID_STATUS CODE=1 (OK) [0 00:01:14.0672] [ 72.217656] awl13: WID_STATUS CODE=0 (DISCONNECTED) [0 00:01:14.0672] [ 72.222558] awl13: disconnected! (ここでフリーズ！) [0 00:01:26.0344] [ 83.915912] awl13: WID_STATUS CODE=1 (OK) [0 00:01:26.0469] meas, 0060.000, F, F,,, [0 00:01:26.0469] meas, 0061.000, F, F,,, [0 00:01:26.0469] meas, 0066.000, F, F, 26.01[ 83.968653] awl13: WID_STATUS CODE=0 (DISCONNECTED) [0 00:01:26.0469] [ 83.976205] awl13: disconnected! [0 00:01:26.0469] , 25.99, 26.03, 25.56, 25.52, 25.18, -0.00, 0.87, 0.41, 000, F [0 00:01:26.0469] meas, 0067.000, F, F,,, [0 00:01:26.0469] meas, 0068.000, F, F,,, [0 00:01:26.0469] meas, 0069.000, F, F,,, [0 00:01:26.0484] meas, 0070.000, F, F,,, [0 00:01:26.0484] meas, 0071.000, F, F,,, (ここでフリーズ！) [0 00:01:38.0094] [ 95.667540] awl13: WID_STATUS CODE=1 (OK) [0 00:01:38.0219] meas, 0072.000, F, F,,, [0 00:01:38.0219] meas, 0073.000, F, F,,, ...
自動起動のサービス(call_script_A640_unit.serviceI)は以下です。
[Unit] Description = call program daemon After = systemd-networkd-wait-online.service [Service] ExecStart = /usr/local/bin/call_program_A640.sh Restart = no Type = simple StandardOutput = tty [Install] WantedBy = multi-user.target
サービスから呼び出されるスクリプト(call_program_A640.sh)は以下です。
#!/bin/sh
echo start call_program
# ネットワーク関連セットアップを非同期で開始しておく
{
ifup eth0
ifup awlan0
# 時刻を取得できたら現在時刻を表示
echo date
eval date
} &
my_program="/usr/local/bin/myApp"
eval $my_program/etc/network/interfacesの中身は以下です。
# interfaces(5) file used by ifup(8) and ifdown(8)
allow-hotplug eth0
auto lo
iface lo inet loopback
iface eth0 inet dhcp
iface awlan0 inet dhcp
pre-up iwpriv awlan0 set_psk (ぱすわーど)
pre-up iwpriv awlan0 set_cryptmode WPA2-AES
pre-up iwconfig awlan0 essid (まいSSID)
wireless-mode managed| ファイル | ファイルの説明 |
|---|---|
| teraterm_起動_640_200813_WLAN自動起動.log |
コメント
fukasawa
fukasawa
いろいろ実験して、わかったことを追記します。
以下のフォーラムを参考にしました。
https://armadillo.atmark-techno.com/forum/armadillo/3345
どうも自動起動のサービス(call_script_A640_unit.serviceI)の中`After=`の欄に記述していたサービス自体が無効状態だったので、有効化しました。
root@armadillo:~# systemctl enable systemd-networkd root@armadillo:~# systemctl enable systemd-networkd-wait-online
その後再起動すると、ログの内容が代わり、今まで17秒ぐらいでアプリケーションが起動していたのが、2分23秒ほどかかるようにり、起動後直後にも10秒ほどフリーズしてしまいました。
Teratermのログ抜粋
[0 00:00:16.0515] [ OK ] Started OpenBSD Secure Shell server. [0 00:00:21.0594] [* ] A start job is running for Wait for… to be Configured (12s / no limit)[** ] A start job... [0 00:01:05.0062] [ 61.435828] random: 6 urandom warning(s) missed due to ratelimiting [0 00:01:05.0094] [ *** ] A start job is running for Wait for… to be Configured (56s / no limit)[ *** ] A start job... [0 00:02:11.0640] See 'systemctl status systemd-networkd-wait-online.service' for details. ... [0 00:02:23.0797] meas, 0001.000, F, F,,, ... [0 00:02:23.0797] meas, 0008.000, F, F,,, [0 00:02:35.0453] [ 151.831434] awl13: WID_STATUS CODE=1 (OK) [0 00:02:35.0578] meas, 0009.000, F, F,,,
at_akihito.irie
入江です。
call_program_A640.sh内の
eval $my_program
を
eval nice -n -20 $my_program
にして試していただけますか？
#!/bin/sh
echo start call_program
# ネットワーク関連セットアップを非同期で開始しておく
{
ifup eth0
ifup awlan0
# 時刻を取得できたら現在時刻を表示
echo date
eval date
} &
my_program="/usr/local/bin/myApp"
eval nice -n -20 $my_program #この行を編集fukasawa
回答ありがとうございます。
いただいたコマンドに変更しました。
systemd-networkdとsystemd-networkd-wait-onlineを無効・有効にした状態の両方を試してみましたが、変更前とあまり差異はなかったようにみえます。
無効状態の場合はアプリケーションが17秒ぐらいで起動して、1:33~1:45と1:47~1:57の間でフリーズしています。
ログ抜粋（無効状態）
[0 00:00:16.0640] meas, 0001.000, F, F,,, [0 00:00:16.0640] DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 9 [0 00:00:17.0593] meas, 0002.000, F, F,,, ... [0 00:01:31.0609] meas, 0076.000, F, F,,, [0 00:01:31.0906] start up awlan0 [0 00:01:32.0609] meas, 0077.000, F, F,,, [0 00:01:32.0984] [ 91.235215] awl13: WID_STATUS CODE=0 (DISCONNECTED) [0 00:01:32.0984] [ 91.240117] awl13: disconnected! [0 00:01:32.0984] [ 91.243490] awl13: WID_STATUS CODE=1 (OK) [0 00:01:33.0609] meas, 0078.000, F, F,,, [0 00:01:33.0687] [ 91.937996] awl13: WID_STATUS CODE=0 (DISCONNECTED) [0 00:01:33.0687] [ 91.942902] awl13: disconnected! [0 00:01:45.0375] [ 103.636601] awl13: WID_STATUS CODE=1 (OK) [0 00:01:45.0468] meas, 0079.000, F, F,,, ... [0 00:01:47.0593] meas, 0091.000, F, F,,, [0 00:01:57.0375] [ 115.545976] awl13: WID_STATUS CODE=1 (OK) [0 00:01:57.0375] meas, 0092.000, F, F,,,
有効状態の場合はアプリケーションが2分21秒ぐらいで起動して、2:22~2:34と3:21~3:26の間でフリーズしています。
ログ抜粋（有効状態）
[0 00:02:22.0094] meas, 0008.000, F, F,,, [0 00:02:22.0360] [ 141.154382] awl13: WID_STATUS CODE=0 (DISCONNECTED) [0 00:02:22.0360] [ 141.159286] awl13: disconnected! [0 00:02:34.0047] [ 152.853147] awl13: WID_STATUS CODE=1 (OK) [0 00:02:34.0157] meas, 0009.000, F, F,,, ... [0 00:03:21.0094] meas, 0067.000, F, F,,, [0 00:03:26.0594] meas, 0068.000, F, F,,,
at_akihito.irie
fukasawa
> ifupが完了した後にmyAppを実行するようにした場合にも同様にフリーズが
> 発生するかお試しいただけますでしょうか？
実行してみました。
アプリケーションの起動後のフリーズはなくなりました。
systemd-networkdとsystemd-networkd-wait-onlineは無効にしています。
[0 00:00:19.0641] armadillo login: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 13 [0 00:00:37.0500] DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 13 [0 00:00:50.0500] DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 20 [0 00:01:05.0110] [ 63.392378] random: crng init done [0 00:01:05.0110] [ 63.395806] random: 6 urandom warning(s) missed due to ratelimiting [0 00:01:10.0407] DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 3 [0 00:01:13.0313] No DHCPOFFERS received. ... [0 00:01:13.0844] [ 72.119330] awl13: disconnected! [0 00:01:25.0516] [ 83.813311] awl13: WID_STATUS CODE=1 (OK) [0 00:01:25.0579] [ 83.854177] awl13: WID_STATUS CODE=0 (DISCONNECTED) [0 00:01:25.0579] [ 83.859079] awl13: disconnected! [0 00:01:37.0266] [ 95.553063] awl13: WID_STATUS CODE=1 (OK) ... [0 00:01:37.0672] [ 95.944808] awl13: connected! [0 00:01:44.0047] DHCPREQUEST of 192.168.1.200 on awlan0 to 255.255.255.255 port 67 ... [0 00:01:50.0094] meas, 0001.000, F, F,,, [0 00:01:51.0110] meas, 0002.000, F, F,,,
ただ、アプリケーションの起動が1：50ほどかかっていますので、できれば30秒ほどに留めたいです。
アプリケーション内でネットワーク機能は使用していますが、起動直後ではないのでネットワークが有効になるのは5分後でも大丈夫です。
ただ、アプリケーションが2秒以上応答がなくなるのは避けたいと考えています。
systemd-networkdとsystemd-networkd-wait-onlineの有効化や/etc/network/interfaceのautoへのeth0の追加、起動スクリプト内のeth0の削除などもやってみましたが、
WLANが有効にならないか起動時間が長くなる結果しか得られませんでした。
at_akihito.irie
fukasawa
> myApp内で1秒ごとにデータをprintしているようですが、どのような実装で1秒
待っていますか？
正確に言いますと、1秒待機するという処理はしておらず、以下のようになっています。
2つのUARTの送信/受信が可能になるかを待機(selectを使用)
↓
（必要であれば）UARTに送信
↓
ネットワークの状態をチェック
↓
（あれば）UARTから受信
↓
前回print時から1秒以上経過していたら、print
↓
（ループ）
関連する部分だけ抜き出してアプリケーションを作ってみようとする過程で見つけたのですが、
上記ネットワークの状態をチェック、の部分を削除したら、`ifup`を非同期実行にしてもアプリケーションのフリーズは発生しなくなりました。
該当部分にprint出力を追加した、ソースコードを示します。
/**
* @brief IPアドレスの取得 (eth0)
*
* @param ip_address 取得したIPアドレス文字列 (eth0)
* @param size 許容文字列長
* @return true 取得成功
* @return false 取得失敗
*/
bool get_current_ip_address(char *ip_address, int size)
{
printf("get_current_ip_address start");
int fd = socket(AF_INET, SOCK_DGRAM, 0);
struct ifreq ifr = {.ifr_addr.sa_family = AF_INET};
strncpy(ifr.ifr_name, "eth0", IFNAMSIZ - 1);
printf("get_current_ip_address before ioctl");
ioctl(fd, SIOCGIFADDR, &ifr);
printf("get_current_ip_address after ioctl");
close(fd);
struct in_addr addr_bin = ((struct sockaddr_in *)&ifr.ifr_addr)->sin_addr;
printf("get_current_ip_address checked");
if (addr_bin.s_addr <= 1)
return false;
snprintf(ip_address, size, "%s", inet_ntoa(addr_bin));
printf("get_current_ip_address end");
return true;
}このコードでは"eth0"のIPアドレスを取得しようとして、2文字以上のアドレス値が取得できなければ、ネットワークに接続していない、と判断しています。
ちなみに問題が解決したら、ここに"awlan0"のチェックを追加して、どちらかのIPアドレスが有効ならネットワークに接続しているとみなす方式に変更する予定です。
削除したコードを有効にしますと、"get_current_ip_address before ioctl"の文字が出力された後にフリーズしています。
ですので、`ioctl(fd, SIOCGIFADDR, &ifr)`がフリーズの発生原因のようです。
ArmadilloというよりはC言語の問題のようですが、ここの修正方法わかりますでしょうか。
もし難しければ、ネットワークのチェック部分を別アプリケーションにして、一時ファイル経由などで本アプリケーションにするのがよいでしょうか？
at_akihito.irie
fukasawa
時間が空いてしまいましたが、無事に解決しましたので、報告させていただきます。
以下の作業の結果、アプリケーションの起動は14秒、非同期でWLANが起動してIPアドレスが確認できるようになり、その際にアプリケーションの動作も問題ありませんでした。
ネットワーク確認部分を別のシェルスクリプトに移動しました。
シェルスクリプトでは`hostname -I`でIPアドレスを取得して、一時ファイル(/run/）に保存します。
その上で、元のC言語のプラグラムはその一時ファイルのみ、定期的に確認するようにしました。
別スクリプト
#!/bin/bash
ip_addrs=
# 1秒おきにIPアドレスを確認して、6文字以上だったら変数に保存する
while [ "${#ip_addrs}" -lt 6 ]
do
# hostname -IでIPアドレスを含む情報を取得して、正規表現でIPアドレスのみにする
ip_addrs=$(hostname -I | grep -oP '\d+(\.\d+){3}')
echo ip_addrs = $ip_addrs
sleep 1
done
# 複数のIPアドレスが取得されることがあるので、配列に変換して、最初だけ取得する。
# WiFiと有線LANの場合は有線LANが取得される。
ip_addrs_array=($ip_addrs)
first_ip_addr=${ip_addrs_array[0]}
# IPアドレスを一時ファイルに保存する
dir_path="/run/myApp/"
output_path=${dir_path}current_ip_addr.txt
mkdir -p $dir_path
echo $first_ip_addr > $output_path
echo "Current ip address is in "$output_path呼び出しスクリプトです。
nice のパラメータが-20ですと、ログインが困難だったので-10に変更しました。
#!/bin/sh
echo start call_program
# ネットワーク関連セットアップを非同期で開始しておく
{
ifup eth0
ifup awlan0
echo date
eval date
# IPアドレスを取得して、一時ファイルの保存するスクリプト
find_ip_script="/usr/local/bin/find_ip_addr.sh"
eval $find_ip_script
} &
my_program="/usr/local/bin/ｍｙApp"
eval nice -n -10 $my_program
at_akihito.irie
2020年8月17日 17時33分
入江です。
1点確認させてください。
添付いただいたログを見る限り、お使いのアプリケーションはフリーズ時に出
力が遅れているだけで、データの取得は毎秒行っており欠損はないように見え
ますが、この挙動では問題があるということでしょうか？