orbstack的一个网络问题

最近搞个openvpn的问题，然后突然发现其实openvpn是已经拨通了的，但是我ping一个只有内网使用的域名时候居然会有10秒的延迟，我一般也等不了10秒就中断了，后面偶然等了会，发现第一个包回过来之后，后面的包都正常回了，就是第一个包要等待十秒。

一开始还以为是openvpn server的问题，可自己抓包一看，发现就是自己请求慢了，而且就是第一个包请求的时候。

自己是mac上的orbstack的镜像，一度还以为是ubuntu的问题，然后试了一下rocky，发现居然也是第一个包延迟十秒。但是同样ping 内网ip却没有任何问题。本着刨根问底的精神，那就先用strace看看系统调用的情况。

root@personal-ubuntu:/Users/timo# strace -tt -T -v -s 1024 ping docs.timoq.com
21:51:46.590522 sendto(3, "\10\0\310n\2 !\"#$%&'()*+,-./01234567", 64, 0, {sa_family=AF_INET, sin_port=htons(0), sin_addr=inet_addr("192.168.1.23")}, 16) = 64 <0.000086>
21:51:46.590640 recvmsg(3, {msg_name={sa_family=AF_INET, sin_port=htons(0), sin_addr=inet_addr("192.168.1.23")}, msg_namelen=128 => 16, msg_iov=[{iov_base="E\0\0Tz\267\0\0d\1 !\"#$%&'()*+,-./01234567", iov_len=192}], msg_iovlen=1, msg_control=[{cmsg_len=32, cmsg_level=SOL_SOCKET, cmsg_type=SO_TIMESTAMP_OLD, cmsg_data={tv_sec=1734004306, tv_usec=642790}}], msg_controllen=32, msg_flags=0}, 0) = 84 <0.052232>
21:51:46.643123 newfstatat(AT_FDCWD, "/etc/resolv.conf", {st_dev=makedev(0, 0x15), st_ino=5014356, st_mode=S_IFREG|0644, st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096, st_blocks=8, st_size=242, st_atime=1733731514 /* 2024-12-09T16:05:14.000848465+0800 */, st_atime_nsec=848465, st_mtime=1733731514 /* 2024-12-09T16:05:14.000848465+0800 */, st_mtime_nsec=848465, st_ctime=1733731514 /* 2024-12-09T16:05:14.000848465+0800 */, st_ctime_nsec=848465}, 0) = 0 <0.000029>
21:51:46.643305 newfstatat(AT_FDCWD, "/etc/nsswitch.conf", {st_dev=makedev(0, 0x26), st_ino=47456, st_mode=S_IFREG|0644, st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096, st_blocks=8, st_size=526, st_atime=1731225143 /* 2024-11-10T15:52:23+0800 */, st_atime_nsec=0, st_mtime=1731225143 /* 2024-11-10T15:52:23+0800 */, st_mtime_nsec=0, st_ctime=1731403213 /* 2024-11-12T17:20:13.204275122+0800 */, st_ctime_nsec=204275122}, 0) = 0 <0.000008>
21:51:46.643415 openat(AT_FDCWD, "/etc/hosts", O_RDONLY|O_CLOEXEC) = 5 <0.000018>
21:51:46.643665 fstat(5, {st_dev=makedev(0, 0x26), st_ino=47389, st_mode=S_IFREG|0644, st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096, st_blocks=8, st_size=135, st_atime=1731225151 /* 2024-11-10T15:52:31+0800 */, st_atime_nsec=0, st_mtime=1731463506 /* 2024-11-13T10:05:06.277574562+0800 */, st_mtime_nsec=277574562, st_ctime=1731463506 /* 2024-11-13T10:05:06.277574562+0800 */, st_ctime_nsec=277574562}) = 0 <0.000008>
21:51:46.643771 lseek(5, 0, SEEK_SET)   = 0 <0.000003>
21:51:46.643796 read(5, "127.0.1.1\tpersonal-ubuntu\n127.0.0.1\tlocalhost\n::1\t\tlocalhost ip6-localhost ip6-loopback\nff02::1\t\tip6-allnodes\nff02::2\t\tip6-allrouters\n\n", 4096) = 135 <0.000006>
21:51:46.643832 read(5, "", 4096)       = 0 <0.000002>
21:51:46.643855 close(5)                = 0 <0.000004>
21:51:46.643879 socket(AF_INET, SOCK_DGRAM|SOCK_CLOEXEC|SOCK_NONBLOCK, IPPROTO_IP) = 5 <0.000017>
21:51:46.643914 setsockopt(5, SOL_IP, IP_RECVERR, [1], 4) = 0 <0.000006>
21:51:46.643947 connect(5, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("0.250.250.200")}, 16) = 0 <0.000042>
21:51:46.644065 ppoll([{fd=5, events=POLLOUT}], 1, {tv_sec=0, tv_nsec=0}, NULL, 0) = 1 ([{fd=5, revents=POLLOUT}], left {tv_sec=0, tv_nsec=0}) <0.000007>
21:51:46.644125 sendto(5, "_N\1\0\0\1\0\0\0\0\0\1\00270\003108\00218\003172\7in-addr\4arpa\0\0\f\0\1\0\0)\4\260\0\0\0\0\0\0", 55, MSG_NOSIGNAL, NULL, 0) = 55 <0.000095>
21:51:46.644278 ppoll([{fd=5, events=POLLIN}], 1, {tv_sec=5, tv_nsec=0}, NULL, 0) = 0 (Timeout) <5.009569>
21:51:51.653958 ppoll([{fd=5, events=POLLOUT}], 1, {tv_sec=0, tv_nsec=0}, NULL, 0) = 1 ([{fd=5, revents=POLLOUT}], left {tv_sec=0, tv_nsec=0}) <0.000010>
21:51:51.654105 sendto(5, "_N\1\0\0\1\0\0\0\0\0\1\00270\003108\00218\003172\7in-addr\4arpa\0\0\f\0\1\0\0)\4\260\0\0\0\0\0\0", 55, MSG_NOSIGNAL, NULL, 0) = 55 <0.000114>
21:51:51.654310 ppoll([{fd=5, events=POLLIN}], 1, {tv_sec=5, tv_nsec=0}, NULL, 0) = 0 (Timeout) <5.010178>
21:51:56.664628 close(5)                = 0 <0.000068>
21:51:56.664876 write(1, "64 bytes from 192.168.1.23: icmp_seq=1 ttl=100 time=52.3 ms\n", 6164 bytes from 192.168.1.23: icmp_seq=1 ttl=100 time=52.3 ms
) = 61 <0.000011>

再来看一个直接ping ip的。

root@personal-ubuntu:/Users/timo# strace -tt -T -v -s 1024 ping 192.168.1.23
21:57:55.828938 sendto(3, "\10\0\30\301\2\216\0\1 !\"#$%&'()*+,-./01234567", 64, 0, {sa_family=AF_INET, sin_port=htons(0), sin_addr=inet_addr("192.168.1.23")}, 16) = 64 <0.000092>
21:57:55.829098 recvmsg(3, {msg_name={sa_family=AF_INET, sin_port=htons(0), sin_addr=inet_addr("192.168.1.23")}, msg_namelen=128 => 16, msg_iov=[{iov_base="E\0\0Tz\267\0\0d\1\ !\"#$%&'()*+,-./01234567", iov_len=192}], msg_iovlen=1, msg_control=[{cmsg_len=32, cmsg_level=SOL_SOCKET, cmsg_type=SO_TIMESTAMP_OLD, cmsg_data={tv_sec=1734004675, tv_usec=871853}}], msg_controllen=32, msg_flags=0}, 0) = 84 <0.042814>
21:57:55.872109 write(1, "64 bytes from 192.168.1.23: icmp_seq=1 ttl=100 time=42.9 ms\n", 6164 bytes from 192.168.1.23: icmp_seq=1 ttl=100 time=42.9 ms) = 61 <0.000014>

我这里是精简了strace的输出内容，实际内容可能要200行左右。我们可以很明显的看到ping域名的时候，在21:51:46.64427和21:51:51.654310有2次ppoll调用超时。再往上看我们可以发现这里会读取**/etc/resolv.conf和/etc/nsswitch.conf**这两个文件。

那会不会是这2个文件有什么问题。看了一眼果然是有问题。这里明晃晃的写着nameserver是 0.250.250.200，那就改成一个公网dns server试试。

在orbstack镜像里这个文件是无法修改的，需要先unlink.在重新生成一下。

unlink /etc/resolv.conf
echo "nameserver 223.5.5.5" > /etc/resolv.conf

这样改完再测试，发现果然正常了，再也没有延迟了。

那么还有什么隐藏的问题吗？

第一个问题为什么在那10秒的时候会有一个5这个socket，然后过了10秒后就没了。这个我有个猜想，但是需要验证一下。

第二个问题是其实域名记录已经在一开始就解析了，为什么后面还要再进行解析。而且为什么第一次解析非常快呢，这个后面再慢慢分析strace的结果看看。