当我们尝试通过 sd_bus_call_method(...) 接口切换 wifi 网络时,调用失败并显示 dbus 超时消息。首先从当前的 wifi 断开并连接确实可以工作,所以这似乎不是我们如何进行连接部分的问题。我们正在使用 Connman 1.37、systemd 2.41 构建 Warrior Yocto。以下是来自失败连接的一些日志:
Jan 8 20:05:22 rc8000-5e2b avahi-daemon[195]: Withdrawing address record for 192.168.170.128 on wlan0.
Jan 8 20:05:22 rc8000-5e2b avahi-daemon[195]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.170.128.
Jan 8 20:05:22 rc8000-5e2b wpa_supplicant[361]: wlan0: CTRL-EVENT-DISCONNECTED bssid=00:08:2f:ef:04:d3 reason=3 locally_generated=1
Jan 8 20:05:22 rc8000-5e2b systemd-networkd[217]: wlan0: Lost carrier
Jan 8 20:05:22 rc8000-5e2b avahi-daemon[195]: Interface wlan0.IPv4 no longer relevant for mDNS.
Jan 8 20:05:22 rc8000-5e2b avahi-daemon[195]: Withdrawing address record for fe80::76e1:82ff:fe08:5e2b on wlan0.
Jan 8 20:05:22 rc8000-5e2b connmand[5042]: wlan0 {del} address 192.168.170.128/22 label wlan0
Jan 8 20:05:22 rc8000-5e2b connmand[5042]: wlan0 {del} route 192.168.168.0 gw 0.0.0.0 scope 253 <LINK>
Jan 8 20:05:22 rc8000-5e2b connmand[5042]: wlan0 {RX} 11740 packets 1072648 bytes
Jan 8 20:05:22 rc8000-5e2b connmand[5042]: wlan0 {TX} 373 packets 56170 bytes
Jan 8 20:05:22 rc8000-5e2b connmand[5042]: wlan0 {update} flags 36867 <UP>
Jan 8 20:05:22 rc8000-5e2b connmand[5042]: wlan0 {newlink} index 3 address 74:E1:82:08:5E:2B mtu 1500
Jan 8 20:05:22 rc8000-5e2b connmand[5042]: wlan0 {newlink} index 3 operstate 2 <DOWN>
Jan 8 20:05:22 rc8000-5e2b connmand[5042]: wlan0 {del} route fe80:: gw :: scope 0 <UNIVERSE>Jan 8 20:05:22 rc8000-5e2b connmand[5042]: wlan0 {del} route ff00:: gw :: scope 0 <UNIVERSE>
Jan 8 20:05:23 rc8000-5e2b connmand[5042]: Skipping disconnect of 5769736572_managed_psk, network is connecting.
Jan 8 20:05:28 rc8000-5e2b wpa_supplicant[361]: wlan0: SME: Trying to authenticate with 00:08:2f:ef:04:d0 (SSID='SBSR&D_2.4' freq=2437 MHz)
Jan 8 20:05:29 rc8000-5e2b wpa_supplicant[361]: wlan0: Trying to associate with 00:08:2f:ef:04:d0 (SSID='SBSR&D_2.4' freq=2437 MHz)
Jan 8 20:05:29 rc8000-5e2b connmand[5042]: wlan0 {RX} 11741 packets 1072783 bytes
Jan 8 20:05:29 rc8000-5e2b wpa_supplicant[361]: wlan0: Associated with 00:08:2f:ef:04:d0
Jan 8 20:05:29 rc8000-5e2b connmand[5042]: wlan0 {TX} 373 packets 56170 bytes
Jan 8 20:05:29 rc8000-5e2b connmand[5042]: wlan0 {update} flags 102403 <UP,LOWER_UP>
Jan 8 20:05:29 rc8000-5e2b wpa_supplicant[361]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
Jan 8 20:05:29 rc8000-5e2b connmand[5042]: wlan0 {newlink} index 3 address 74:E1:82:08:5E:2B mtu 1500
Jan 8 20:05:29 rc8000-5e2b connmand[5042]: wlan0 {newlink} index 3 operstate 5 <DORMANT>
Jan 8 20:05:29 rc8000-5e2b wpa_supplicant[361]: wlan0: WPA: Key negotiation completed with 00:08:2f:ef:04:d0 [PTK=CCMP GTK=CCMP]
Jan 8 20:05:29 rc8000-5e2b wpa_supplicant[361]: wlan0: CTRL-EVENT-CONNECTED - Connection to 00:08:2f:ef:04:d0 completed [id=1 id_str=]
Jan 8 20:05:29 rc8000-5e2b connmand[5042]: wlan0 {add} route ff00:: gw :: scope 0 <UNIVERSE>
Jan 8 20:05:29 rc8000-5e2b connmand[5042]: wlan0 {add} route fe80:: gw :: scope 0 <UNIVERSE>
Jan 8 20:05:29 rc8000-5e2b connmand[5042]: wlan0 {RX} 11742 packets 1072952 bytes
Jan 8 20:05:29 rc8000-5e2b systemd-networkd[217]: wlan0: Gained carrier
Jan 8 20:05:29 rc8000-5e2b connmand[5042]: wlan0 {TX} 375 packets 56458 bytes
Jan 8 20:05:29 rc8000-5e2b connmand[5042]: wlan0 {update} flags 102467 <UP,RUNNING,LOWER_UP>
Jan 8 20:05:29 rc8000-5e2b connmand[5042]: wlan0 {newlink} index 3 address 74:E1:82:08:5E:2B mtu 1500
Jan 8 20:05:29 rc8000-5e2b connmand[5042]: wlan0 {newlink} index 3 operstate 6 <UP>
Jan 8 20:05:30 rc8000-5e2b wpa_supplicant[361]: wlan0: CTRL-EVENT-SIGNAL-CHANGE above=0 signal=-48 noise=9999 txrate=58500
Jan 8 20:05:30 rc8000-5e2b avahi-daemon[195]: Joining mDNS multicast group on interface wlan0.IPv4 with address 10.175.79.251.
Jan 8 20:05:30 rc8000-5e2b avahi-daemon[195]: New relevant interface wlan0.IPv4 for mDNS.
Jan 8 20:05:30 rc8000-5e2b avahi-daemon[195]: Registering new address record for 10.175.79.251 on wlan0.IPv4.
Jan 8 20:05:30 rc8000-5e2b connmand[5042]: wlan0 {add} address 10.175.79.251/21 label wlan0 family 2Jan 8 20:05:30 rc8000-5e2b systemd-networkd[217]: wlan0: Gained IPv6LL
Jan 8 20:05:30 rc8000-5e2b avahi-daemon[195]: Registering new address record for fe80::76e1:82ff:fe08:5e2b on wlan0.*.
Jan 8 20:05:30 rc8000-5e2b connmand[5042]: wlan0 {add} route 10.175.72.0 gw 0.0.0.0 scope 253 <LINK>
Jan 8 20:05:30 rc8000-5e2b connmand[5042]: wlan0 {add} route 10.175.72.1 gw 0.0.0.0 scope 253 <LINK>
Jan 8 20:05:30 rc8000-5e2b connmand[5042]: wlan0 {add} route 0.0.0.0 gw 10.175.72.1 scope 0 <UNIVERSE>
Jan 8 20:05:47 rc8000-5e2b connman-client[5046]: Service Connect wifi_74e182085e2b_5342535226445f322e34_managed_psk: org.freedesktop.DBus.Error.Timeout
同样问题的 dbus 跟踪:
method call time=1578952131.483910 sender=:1.22 -> destination=net.connman serial=20 path=/net/connman/service/wifi_74e182085e2b_5342535226445f322e34_managed_psk; interface=net.connman.Service; member=Connect
method call time=1578952131.507736 sender=:1.21 -> destination=fi.w1.wpa_supplicant1 serial=3697 path=/fi/w1/wpa_supplicant1/Interfaces/5; interface=fi.w1.wpa_supplicant1.Interface; member=Disconnect
signal time=1578952131.512794 sender=:1.21 -> destination=(null destination) serial=3698 path=/net/connman/service/wifi_74e182085e2b_5769736572_managed_psk; interface=net.connman.Service; member=PropertyChanged
string "Domains"
variant array [
]
signal time=1578952131.639802 sender=:1.21 -> destination=(null destination) serial=3699 path=/; interface=net.connman.Manager; member=PropertyChanged
string "State"
variant string "ready"
... Trimmed because too long ...
signal time=1578952132.045699 sender=:1.21 -> destination=(null destination) serial=3713 path=/net/connman/service/wifi_74e182085e2b_5769736572_managed_psk; interface=net.connman.Service; member=PropertyChanged
string "State"
variant string "association"
method call time=1578952132.054770 sender=:1.21 -> destination=fi.w1.wpa_supplicant1 serial=3714 path=/fi/w1/wpa_supplicant1/Interfaces/5; interface=fi.w1.wpa_supplicant1.Interface; member=RemoveNetwork
object path "/fi/w1/wpa_supplicant1/Interfaces/5/Networks/0"signal time=1578952132.066571 sender=:1.21 -> destination=(null destination) serial=3715 path=/; interface=net.connman.Manager;
... Trimmed because too long ...
signal time=1578952147.533836 sender=:1.21 -> destination=(null destination) serial=3750 path=/net/connman/technology/wifi; interface=net.connman.Technology; member=PropertyChanged
string "Connected
variant boolean true
signal time=1578952147.536193 sender=:1.21 -> destination=(null destination) serial=3751 path=/; interface=net.connman.Manager; member=PropertyChanged
string "State"
variant string "ready"
signal time=1578952147.536811 sender=:1.21 -> destination=(null destination) serial=3752 path=/net/connman/service/wifi_74e182085e2b_5342535226445f322e34_managed_psk; interface=net.connman.Service; member=PropertyChanged
string "IPv4"
variant array [
]
signal time=1578952147.543999 sender=:1.21 -> destination=(null destination) serial=3753 path=/net/connman/service/wifi_74e182085e2b_5342535226445f322e34_managed_psk; interface=net.connman.Service; member=PropertyChanged
string "IPv4"
variant array [
]
... Trimmed because too long ...```
我注意到 dbus 跟踪中的 IP 信息似乎不完整,并且 connman 状态永远不会在线。我还注意到在 syslog 中为成功连接添加了额外的路由:
Jan 12 20:33:54 rc8000-5e2b avahi-daemon[205]: Registering new address record for 192.168.171.81 on wlan0.IPv4.
Jan 12 20:33:54 rc8000-5e2b connmand[222]: wlan0 {add} address 192.168.171.81/22 label wlan0 family 2
Jan 12 20:33:54 rc8000-5e2b connmand[222]: wlan0 {add} route 192.168.168.0 gw 0.0.0.0 scope 253 <LINK>
Jan 12 20:33:54 rc8000-5e2b connmand[222]: wlan0 {add} route 192.168.171.254 gw 0.0.0.0 scope 253 <LINK>
Jan 12 20:33:54 rc8000-5e2b connmand[222]: wlan0 {add} route 8.8.8.8 gw 192.168.171.254 scope 0 <UNIVERSE>
Jan 12 20:33:54 rc8000-5e2b connmand[222]: wlan0 {add} route 8.8.4.4 gw 192.168.171.254 scope 0 <UNIVERSE>
Jan 12 20:33:54 rc8000-5e2b connmand[222]: wlan0 {add} route 0.0.0.0 gw 192.168.171.254 scope 0 <UNIVERSE>
Jan 12 20:33:54 rc8000-5e2b connmand[222]: wlan0 {add} route 212.227.81.55 gw 192.168.171.254 scope 0 <UNIVERSE>
最后一个似乎是“电话回家”IP,用于确定设备在线。它稍后会消失,并且 connman 确实进入了在线状态。
我非常困惑为什么 connman (或 systemd ?)在尝试在没有先断开连接的情况下在 wifi 网络之间切换时表现得那样。任何帮助,将不胜感激。
编辑以下跟踪显示同时进行的 2 个关联
signal time=1578952132.045699 sender=:1.21 -> destination=(null destination) serial=3713 path=/net/connman/service/wifi_74e182085e2b_5769736572_managed_psk; interface=net.connman.Service; member=PropertyChanged
string "State"
variant string "association"
method call time=1578952132.054770 sender=:1.21 -> destination=fi.w1.wpa_supplicant1 serial=3714 path=/fi/w1/wpa_supplicant1/Interfaces/5; interface=fi.w1.wpa_supplicant1.Interface; member=RemoveNetwork
object path "/fi/w1/wpa_supplicant1/Interfaces/5/Networks/0"
signal time=1578952132.066571 sender=:1.21 -> destination=(null destination) serial=3715 path=/; interface=net.connman.Manager; member=ServicesChanged
....
signal time=1578952132.471595 sender=:1.21 -> destination=(null destination) serial=3718 path=/net/connman/service/wifi_74e182085e2b_5342535226445f322e34_managed_psk; interface=net.connman.Service; member=PropertyChanged
string "State"
variant string "association"
signal time=1578952132.577805 sender=:1.21 -> destination=(null destination) serial=3719 path=/; interface=net.connman.Manager; member=ServicesChanged
....
method return time=1578952133.177367 sender=:1.10 -> destination=:1.21 serial=84264 reply_serial=3716
object path "/fi/w1/wpa_supplicant1/Interfaces/5/Networks/0"
method call time=1578952133.181592 sender=:1.21 -> destination=fi.w1.wpa_supplicant1 serial=3720 path=/fi/w1/wpa_supplicant1/Interfaces/5; interface=fi.w1.wpa_supplicant1.Interface; member=SelectNetwork
object path "/fi/w1/wpa_supplicant1/Interfaces/5/Networks/0"
signal time=1578952133.199893 sender=:1.10 -> destination=(null destination) serial=84265 path=/fi/w1/wpa_supplicant1/Interfaces/5; interface=fi.w1.wpa_supplicant1.Interface; member=NetworkAdded
object path "/fi/w1/wpa_supplicant1/Interfaces/5/Networks/1"