私の質問
AF_NETLINK次のトレースに示すように、カーネルのクエリに応答するのに断続的に数秒かかりますstrace。
10:42:38.864353 socket(AF_NETLINK, SOCK_RAW|SOCK_CLOEXEC, NETLINK_ROUTE) = 3
10:42:38.864377 setsockopt(3, SOL_SOCKET, SO_SNDBUF, [32768], 4) = 0
10:42:38.864399 setsockopt(3, SOL_SOCKET, SO_RCVBUF, [1048576], 4) = 0
10:42:38.864418 setsockopt(3, SOL_NETLINK, NETLINK_EXT_ACK, [1], 4) = 0
10:42:38.864436 bind(3, {sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, 12) = 0
10:42:38.864459 getsockname(3, {sa_family=AF_NETLINK, nl_pid=16296, nl_groups=00000000}, [12]) = 0
10:42:38.864491 sendto(3, {{len=40, type=RTM_GETLINK, flags=NLM_F_REQUEST|NLM_F_DUMP, seq=1588581759, pid=0}, {ifi_family=AF_UNSPEC, ifi_type=ARPHRD_NETROM, ifi_index=0, ifi_flags=0, ifi_change=0}, {{nla_len=8, nla_type=IFLA_EXT_MASK}, 1}}, 40, 0, NULL, 0) = 40
10:42:51.894848 recvmsg(3, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base=NULL, iov_len=0}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_TRUNC}, MSG_PEEK|MSG_TRUNC) = 2608
背景
IPアドレスの確認中に時々ソフトウェアがハングすることがわかりました。主にブラウザですが、新しいブラウザsshやDNSを必要とする他のブラウザもあります。
Wiresharkを使用して、DNSクエリパケットがネームサーバーに送信される前にHangが発生し、それ自体が遅延するネームサーバーではなかったことを確認できました。
一部の関連プロセスを追跡してみると、このプロセスが最初に/etc/resolv.confIPV6アドレスにデータを読み取ることがわかります。
# Generated by NetworkManager
search example.de otherexample.de
nameserver 192.168.178.1
nameserver 2a02:8070:c19e:b400:xxxx:xxxx:xxxx:xxxx
nameserver fd00::9a9b:cbff:xxxx:xxxx
次に、コメントのみを含む内容を読み、/etc/gai.confAF_NETLINKソケットを使用してインターフェイスのリストを取得します。
ほとんどの場合、sendtoそのrecvmsg時間間隔はわずか数ミリ秒ですが、場合によっては永遠に停止するように感じます。
これにより、問題はDNSにあるのではないという事実に気づきました。実際、ip aループが時々数秒間中断されることもありました。だから私は各IPをand logging the output and the2つの異なるファイルに追跡しながらこれを行いました。これは、問題が約1分ごとに1回発生し、約12〜13秒間持続することを示しています。
10:41:58.561713 sendto(3, {{len=40, type=RTM_GETLINK, flags=NLM_F_REQUEST|NLM_F_DUMP, seq=1588581719, pid=0}, {ifi_family=AF_UNSPEC, ifi_type=ARPHRD_NETROM, ifi_index=0, ifi_flags=0, ifi_change=0}, {{nla_len=8, nla_type=IFLA_EXT_MASK}, 1}}, 40, 0, NULL, 0) = 40
10:41:58.561943 recvmsg(3, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base=NULL, iov_len=0}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_TRUNC}, MSG_PEEK|MSG_TRUNC) = 2608
10:42:38.864491 sendto(3, {{len=40, type=RTM_GETLINK, flags=NLM_F_REQUEST|NLM_F_DUMP, seq=1588581759, pid=0}, {ifi_family=AF_UNSPEC, ifi_type=ARPHRD_NETROM, ifi_index=0, ifi_flags=0, ifi_change=0}, {{nla_len=8, nla_type=IFLA_EXT_MASK}, 1}}, 40, 0, NULL, 0) = 40
10:42:51.894848 recvmsg(3, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base=NULL, iov_len=0}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_TRUNC}, MSG_PEEK|MSG_TRUNC) = 2608
10:43:42.269435 sendto(3, {{len=40, type=RTM_GETLINK, flags=NLM_F_REQUEST|NLM_F_DUMP, seq=1588581823, pid=0}, {ifi_family=AF_UNSPEC, ifi_type=ARPHRD_NETROM, ifi_index=0, ifi_flags=0, ifi_change=0}, {{nla_len=8, nla_type=IFLA_EXT_MASK}, 1}}, 40, 0, NULL, 0) = 40
10:43:54.894689 recvmsg(3, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base=NULL, iov_len=0}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_TRUNC}, MSG_PEEK|MSG_TRUNC) = 2608
10:44:45.276410 sendto(3, {{len=40, type=RTM_GETLINK, flags=NLM_F_REQUEST|NLM_F_DUMP, seq=1588581886, pid=0}, {ifi_family=AF_UNSPEC, ifi_type=ARPHRD_NETROM, ifi_index=0, ifi_flags=0, ifi_change=0}, {{nla_len=8, nla_type=IFLA_EXT_MASK}, 1}}, 40, 0, NULL, 0) = 40
10:44:57.894722 recvmsg(3, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base=NULL, iov_len=0}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_TRUNC}, MSG_PEEK|MSG_TRUNC) = 2608
10:45:48.273509 sendto(3, {{len=40, type=RTM_GETLINK, flags=NLM_F_REQUEST|NLM_F_DUMP, seq=1588581949, pid=0}, {ifi_family=AF_UNSPEC, ifi_type=ARPHRD_NETROM, ifi_index=0, ifi_flags=0, ifi_change=0}, {{nla_len=8, nla_type=IFLA_EXT_MASK}, 1}}, 40, 0, NULL, 0) = 40
10:46:00.894574 recvmsg(3, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base=NULL, iov_len=0}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_TRUNC}, MSG_PEEK|MSG_TRUNC) = 2608
最初のペアは通常の状況で発生することの例であり、他のペアは問題が1分ごとに1回発生し、約12秒間続く方法を示しています。
この間、ネットワークに大きな変化はありませんでした。以下は、ip a最初の一時停止の前後の出力例です。
Mon May 4 10:42:38 CEST 2020
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN group default qlen 1000
link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
inet 127.0.0.1/8 scope host lo
valid_lft forever preferred_lft forever
inet6 ::1/128 scope host
valid_lft forever preferred_lft forever
2: enp3s0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc fq_codel state UP group default qlen 1000
link/ether a8:5e:45:60:e4:be brd ff:ff:ff:ff:ff:ff
inet 192.168.178.131/24 brd 192.168.178.255 scope global dynamic noprefixroute enp3s0
valid_lft 83515sec preferred_lft 83515sec
inet6 2a02:8070:c19e:b400:bec7:94b4:34f1:86b4/64 scope global dynamic noprefixroute
valid_lft 7078sec preferred_lft 3478sec
inet6 fe80::d27:8efd:f696:3c47/64 scope link noprefixroute
valid_lft forever preferred_lft forever
3: wlp7s0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc mq state UP group default qlen 1000
link/ether d0:ab:d5:0e:02:09 brd ff:ff:ff:ff:ff:ff
inet 192.168.10.10/24 brd 192.168.10.255 scope global dynamic noprefixroute wlp7s0
valid_lft 602858sec preferred_lft 602858sec
inet6 fe80::c694:6683:6353:e9c9/64 scope link noprefixroute
valid_lft forever preferred_lft forever
4: wlxf4f26d08d54e: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc mq state DOWN group default qlen 1000
link/ether f4:f2:6d:08:d5:4e brd ff:ff:ff:ff:ff:ff
Mon May 4 10:42:52 CEST 2020
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN group default qlen 1000
link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
inet 127.0.0.1/8 scope host lo
valid_lft forever preferred_lft forever
inet6 ::1/128 scope host
valid_lft forever preferred_lft forever
2: enp3s0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc fq_codel state UP group default qlen 1000
link/ether a8:5e:45:60:e4:be brd ff:ff:ff:ff:ff:ff
inet 192.168.178.131/24 brd 192.168.178.255 scope global dynamic noprefixroute enp3s0
valid_lft 83514sec preferred_lft 83514sec
inet6 2a02:8070:c19e:b400:bec7:94b4:34f1:86b4/64 scope global dynamic noprefixroute
valid_lft 7077sec preferred_lft 3477sec
inet6 fe80::d27:8efd:f696:3c47/64 scope link noprefixroute
valid_lft forever preferred_lft forever
3: wlp7s0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc mq state UP group default qlen 1000
link/ether d0:ab:d5:0e:02:09 brd ff:ff:ff:ff:ff:ff
inet 192.168.10.10/24 brd 192.168.10.255 scope global dynamic noprefixroute wlp7s0
valid_lft 602857sec preferred_lft 602857sec
inet6 fe80::c694:6683:6353:e9c9/64 scope link noprefixroute
valid_lft forever preferred_lft forever
4: wlxf4f26d08d54e: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc mq state DOWN group default qlen 1000
link/ether f4:f2:6d:08:d5:4e brd ff:ff:ff:ff:ff:ff
質問
カーネルが1分ごとに1回AF_NETLINK/RTM_GETLINKソケット呼び出しへの応答を数秒遅らせる原因は何ですか？
私が知っている限り、これらの呼び出しは他のプロセス（タイムアウトstrace可能）ではなくカーネルによって直接処理されます。そうですか？
それでは、カーネルがこれらの要求をブロックし続けるのは何ですか？デバッグするには？
ベストアンサー1
Eduardo Trapaniのコメントのおかげで、この問題を解決できました。
wlxf4f26d08d54e上記の出力からインターフェースを提供するUSB WIFIアダプタを削除すると、ip a問題がなくなりました。
によると、lsusbデバイスの正確な仕様は次のとおりです。
Bus 001 Device 010: ID 0bda:8179 Realtek Semiconductor Corp. RTL8188EUS 802.11n Wireless Network Adapter
興味深いことに、デバイスのエントリはまったくありません/var/log/syslog。ただし、ブート時にデバイスが認識されてプラグを抜いたため、接続状態が悪かったり、それと似たものではないようです。
~によるとhttps://linux-hardware.org/index.php?id=usb:0bda-8179、このドライバはバージョン3.12からカーネルにあり、ほとんどどこでも動作するので、私の具体的な問題が何であるかわかりません。
しかし、今解決されてよかったです。