本文转载自:http://blog.csdn.net/tankai19880619/article/details/42972551
一、现象
12小时压测wifi连接后,发现网络连接中断;相关log:
我们关心状态变化部分ConnectivityService: ConnectivityChange for WIFI
- 01-19-17:42;0501-01 08:00:38.552 954 1117 D ConnectivityService: --NetworkStateTracker.EVENT_STATE_CHANGED handle--
 - 01-19-17:42;0501-01 08:00:38.552 954 1117 D ConnectivityService: ConnectivityChange for WIFI: CONNECTED/CONNECTED
 - 01-19-17:42;0501-01 08:00:38.552 954 1117 D ConnectivityService: Setting TCP values: [524288,1048576,2097152,262144,524288,1048576] which comes from [net.tcp.buffersize.wifi]
 - /////////////////////////////////////////////////////////////////////////////////////////////////////12hago
 - 01-20-05:14;2201-01 19:33:18.943 1267 1386 V shizx : @@@clienttype:@@@TCL-CN-MT55CD-F3700A-LG
 - 01-20-05:14;22ERROR!!! MlmeEnqueueForRecv: un-recongnized mgmt->subtype=15
 - 01-20-05:14;2301-01 19:33:19.572 954 1808 E Dhinit:
 - 01-20-05:14;23 waitpid returned pid 1835, status = 00000009
 - 01-20-05:14;23cpStateMacinit: process ‘dhcpcd_wlan0‘, pid 1835 exited
 - 01-20-05:14;23hine: DHCP failed on wlan0: Timed out waiting for DHCP Renew to finish
 - 01-20-05:14;2301-01 19:33:19.574 954 1808 D DHCP : ifc_init, return = 0
 - 01-20-05:14;2301-01 19:33:19.574 954 1808 D DHCP : ifc_set_addr(wlan0, xx) = 0
 - 01-20-05:14;2301-01 19:33:19.574 954 1808 D DHCP : ifc_close
 - 01-20-05:14;2301-01 19:33:19.779 954 1115 D WifiHW : send cmd is DRIVER POWERMODE 0
 - 01-20-05:14;2301-01 19:33:19.779 954 1115 D WifiHW : send cmd is DRIVER BTCOEXMODE 2
 - 01-20-05:14;2301-01 19:33:19.781 954 1115 E WifiStateMachine: IP configuration failed
 - 01-20-05:14;2301-01 19:33:19.781 954 1115 D WifiHW : send cmd is DISCONNECT
 - 01-20-05:14;2301-01 19:33:19.782 1558 1558 D wpa_supplicant: wpa_driver_wext_deauthenticate
 - 01-20-05:14;2301-01 19:33:19.789 1558 1558 D wpa_supplicant: wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
 - 01-20-05:14;2301-01 19:33:19.790 1558 1558 D wpa_supplicant: wpa_driver_wext_set_key: alg=0 key_idx=1 set_tx=0 seq_len=0 key_len=0
 - 01-20-05:14;2301-01 19:33:19.790 954 1110 D NetdConnector: RCV <- {600 Iface linkstate wlan0 up}
 - 01-20-05:14;2301-01 19:33:19.793 1558 1558 D wpa_supplicant: wpa_driver_wext_set_key: alg=0 key_idx=2 set_tx=0 seq_len=0 key_len=0
 - 01-20-05:14;2301-01 19:33:19.793 1558 1558 D wpa_supplicant: wpa_driver_wext_set_key: alg=0 key_idx=3 set_tx=0 seq_len=0 key_len=0
 - 01-20-05:14;2301-01 19:33:19.794 1558 1558 D wpa_supplicant: wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
 - 01-20-05:14;2301-01 19:33:19.795 1558 1558 D wpa_supplicant: wpa_driver_wext_set_operstate: operstate 1->0 (DORMANT)
 - 01-20-05:14;2301-01 19:33:19.795 1558 1558 D wpa_supplicant: netlinkinit:
 - 01-20-05:14;23 waitpid returned pid 1126, status = 00000009
 - 01-20-05:14;23init: process ‘dhcpcd_eth0‘, pid 1126 exited
 - 01-20-05:14;23: Operstate: linkmode=-1, operstate=5
 
二、分析
关键部分:
- DhcpStateMachine: DHCP failed on wlan0: Timed out waiting for DHCP Renew to finish
 - init: waitpid returned pid 1835, status = 00000009
 - init: process ‘dhcpcd_wlan0‘, pid 1835 exited
 
1.frameworks/base/core/java/android/net/DhcpStateMachine.java
- private boolean runDhcp(DhcpAction dhcpAction) {
 - if (dhcpAction == DhcpAction.START) {
 - if (DBG) Log.d(TAG, "DHCP request on " + mInterfaceName);
 - success = NetworkUtils.runDhcp(mInterfaceName, dhcpInfoInternal);
 - mDhcpInfo = dhcpInfoInternal;
 - } else if (dhcpAction == DhcpAction.RENEW) {
 - if (DBG) Log.d(TAG, "DHCP renewal on " + mInterfaceName);
 - success = NetworkUtils.runDhcpRenew(mInterfaceName, dhcpInfoInternal); //f分析该函数
 - dhcpInfoInternal.updateFromDhcpRequest(mDhcpInfo);
 - }
 - if (success) {
 - ......
 - } else {
 - //这里就是打印:DhcpStateMachine: DHCP failed on wlan0: Timed out waiting for DHCP Renew to finish
 - Log.e(TAG, "DHCP failed on " + mInterfaceName + ": " +
 - NetworkUtils.getDhcpError());
 - NetworkUtils.stopDhcp(mInterfaceName);
 - mController.obtainMessage(CMD_POST_DHCP_ACTION, DHCP_FAILURE, 0)
 - .sendToTarget();
 - }
 - return success;
 - }
 
2.frameworks/base/core/java/android/net/NetworkUtils.java
- public native static boolean runDhcpRenew(String interfaceName, DhcpInfoInternal ipInfo);
 
3.frameworks/base/core/jni/android_net_NetUtils.cpp
- static jboolean android_net_utils_runDhcpRenew(JNIEnv* env, jobject clazz, jstring ifname, jobject info)
 - {
 - return android_net_utils_runDhcpCommon(env, clazz, ifname, info, true);
 - }
 - static jboolean android_net_utils_runDhcpCommon(JNIEnv* env, jobject clazz, jstring ifname,
 - jobject info, bool renew)
 - {
 - if (renew) {
 - result = ::dhcp_do_request_renew(nameStr, ipaddr, gateway, &prefixLength,
 - dns1, dns2, server, &lease, vendorInfo);
 - }
 - }
 
4.system/core/libnetutils/dhcp_utils.c
- int dhcp_do_request_renew(const char *interface,
 - char *ipaddr,
 - char *gateway,
 - uint32_t *prefixLength,
 - char *dns[],
 - char *server,
 - uint32_t *lease,
 - char *vendorInfo,
 - char *domain,
 - char *mtu)
 - {
 - if (wait_for_property(result_prop_name, NULL, 30) < 0) {
 - snprintf(errmsg, sizeof(errmsg), "%s", "Timed out waiting for DHCP Renew to finish"); //这是最关键的错误部分
 - return -1;
 - }
 - }
 - static int wait_for_property(const char *name, const char *desired_value, int maxwait)
 - {
 - char value[PROPERTY_VALUE_MAX] = {‘\0‘};
 - int maxnaps = (maxwait * 1000) / NAP_TIME;
 - if (maxnaps < 1) {
 - maxnaps = 1;
 - }
 - //add by tank
 - // add for MStar Android Patch Begin
 - maxnaps = maxnaps + 1;
 - usleep(50*1000);
 - // add for MStar Android Patch End
 - //end tank
 - while (maxnaps-- > 0) {
 - usleep(NAP_TIME * 1000);
 - if (property_get(name, value, NULL)) {
 - if (desired_value == NULL ||
 - strcmp(value, desired_value) == 0) {
 - return 0;
 - }
 - }
 - //add by tank@
 - // add for MStar Android Patch Begin
 - usleep(NAP_TIME * 1000);
 - // add for MStar Android Patch End
 - //end tank
 - }
 - return -1; /* failure */
 - }
 
三、解决
合入上处4中add by tank后问题解决。
其他问题,mac地址冲突导致重启后无法获取IP。
- D/NetdConnector( 958): RCV <- {213 5c:36:b8:4d:ab:7a 0.0.0.0 0 [up broadcast multicast]}
 - D/NetdConnector( 958): RSP <- {213 5c:36:b8:4d:ab:7a 0.0.0.0 0 [up broadcast multicast]}
 - D/NetworkManagementService( 958): rsp <213 5c:36:b8:4d:ab:7a 0.0.0.0 0 [up broadcast multicast]>
 - D/NetworkManagementService( 958): flags <[up broadcast multicast]>
 - D/NetworkManagementService( 958): Registering observer
 - I/EthernetStateTracker( 958): reset device eth0
 - D/NetUtils( 958): android_net_utils_resetConnections in env=0x7d6950 clazz=0xad200001 iface=eth0 mask=0x3
 - D/DHCP ( 958): ifc_init, return = 0
 - D/DHCP ( 958): ifc_close
 - D/DHCP ( 958): ifc_init, return = 0
 - D/DHCP ( 958): ifc_up(eth0) = 0
 - D/DHCP ( 958): ifc_close
 - D/DHCP ( 958): ifc_init, return = 0
 - D/DHCP ( 958): ifc_close
 - D/DHCP ( 958): ifc_init, return = 0
 - D/DHCP ( 958): ifc_close
 - D/dhcp ( 1124): enter dhcpcd service
 - D/dhcp ( 1124): enter dhcpcd service add options
 - D/dhcp ( 1124): enter dhcpcd service leave option
 - D/dhcp ( 1124): enter dhcpcd service chdir
 - D/dhcp ( 1124): enter dhcpcd service dump
 - D/dhcp ( 1124): enter dhcpcd service master
 - E/dhcp ( 1124): version 5.2.10 starting
 - D/DHCP ( 1124): ifc_init, return = 0
 - D/DHCP ( 1124): ifc_close
 - F/dhcp ( 1124): eth0: using hwaddr 5c:36:b8:4d:ab:7a
 - F/dhcp ( 1124): eth0: executing `/system/etc/dhcpcd/dhcpcd-run-hooks‘, reason PREINIT
 - I/dhcp ( 1124): host does not support a monotonic clock - timing can skew
 - F/dhcp ( 1124): eth0: reading lease `/data/misc/dhcp/dhcpcd-eth0.lease‘
 - E/dhcp ( 1124): eth0: broadcasting for a lease
 - F/dhcp ( 1124): eth0: sending DISCOVER (xid 0xd92bbde3), next in 3.54 seconds