[Moto X Android Development] hachamacha:
I just took a quick look at the behavior & logs relating to the connect/disconnect dhclient/dhcptool wlan0 problem. If it's worth anything, I notice about half the people complaining say "WiFi disconnects" and the other half say "WiFi won't reconnect automatically". I'm sure that both things are true even if it seems like one is the problem.

If WiFi can't connect itself (or in this case on mine, REconnect itself), then functionally it's a problem of connecting. All these phones, gizmo's, devices, etc, disconnect regularly from their routers, so connecting is much more likely the side to look at (I think). So I finally managed to get logcat under control from ADB and find the one instance where mine disconnected and failed to reconnect. I'll put the log in a code section and the section to look at, I think, is where it marks the access point (for me, lets say it's "kathy") as invalid and then claims it'll not try anymore. It does try over and over again, but this one section is pretty unique and I think is tied up to the event of not being able to reconnect.

Note: My phone with this ROM is booting up and connecting everytime (the first time, at least) to WiFi without problem. It's the times after that that I'm looking for: Another NOTE: All "router names, or passwords, and IP's & NIC's" have been changed a bit to protect the guilty ;;)

Log from an "adb logcat >> {file}" session:

03-23 16:16:05.985 2525 2525 W Settings: Setting airplane_mode_on has moved from android.provider.Settings.System to android.provider.Settings.Global, returning read-only value.
03-23 16:16:06.000 2525 2525 W Settings: Setting airplane_mode_on has moved from android.provider.Settings.System to android.provider.Settings.Global, returning read-only value.
03-23 16:16:06.058 2525 2525 D DX-PowerManager: [Stats] Ignore status report in 12 hours.
03-23 16:16:09.000 1911 24740 W IcingInternalCorpora: getNumBytesRead when not calculated.
03-23 16:16:09.466 916 14277 D NetlinkSocketObserver: NeighborEvent{elapsedMs=22568511, 192.168.1.254, [8461A06C52A0], RTM_DELNEIGH, NUD_NOARP}
03-23 16:16:09.458 24747 24747 I dhcptool: type=1400 audit(0.0:1383): avc: denied { create } for scontext=u:r:init:s0 tcontext=u:r:init:s0 tclass=packet_socket permissive=1
03-23 16:16:09.458 24747 24747 I dhcptool: type=1400 audit(0.0:1384): avc: denied { bind } for scontext=u:r:init:s0 tcontext=u:r:init:s0 tclass=packet_socket permissive=1
03-23 16:16:09.477 2025 14302 V NativeCrypto: Read error: ssl=0x96b84200: I/O error during system call, Connection timed out
03-23 16:16:09.480 2025 14302 V NativeCrypto: SSL shutdown failed: ssl=0x96b84200: I/O error during system call, Broken pipe
03-23 16:16:09.489 1911 16520 I CastDeviceController: [controller-0002 MRP] finishDisconnecting; socketError="2 IO Error", mDisconnectStatusCode=SUCCESS
03-23 16:16:09.489 1911 16520 I CastDeviceController: [controller-0002 MRP] listener.onDisconnected(NETWORK_ERROR)
03-23 16:16:09.489 1911 16520 I CastMediaRouteProvider: CastDeviceController.Listener.onDisconnected: NETWORK_ERROR
03-23 16:16:09.505 916 1538 D ConnectivityService: reportNetworkConnectivity(102, false) by 10012
03-23 16:16:09.505 916 14276 D NetworkMonitor/NetworkAgentInfo [WIFI () - 102]: Forcing reevaluation for UID 10012
03-23 16:16:09.525 916 933 I ActivityManager: Start proc 24751:com.google.android.talk/u0a75 for broadcast com.google.android.talk/com.google.android.apps.hangouts.service.GcmStateReceiver
03-23 16:16:09.527 1911 16520 I CastDeviceController: [controller-0002 MRP] handleConnectionFailure; castStatusCode=NETWORK_ERROR, analytics: 2, mOriginalDisconnectStatusCode=SUCCESS mOriginalAnalyticsErrorCode: 0
03-23 16:16:09.537 916 14276 D NetworkMonitor/NetworkAgentInfo [WIFI () - 102]: Probably not a portal: exception java.net.UnknownHostException: Unable to resolve host "connectivitycheck.gstatic.com": No address associated with hostname
03-23 16:16:09.537 916 1036 D ConnectivityService: NetworkAgentInfo [WIFI () - 102] validation failed
03-23 16:16:09.538 916 1036 D ConnectivityService: notifyType CAP_CHANGED for NetworkAgentInfo [WIFI () - 102]
03-23 16:16:09.539 916 1036 D ConnectivityService: sendStickyBroadcast: action=android.net.conn.INET_CONDITION_ACTION
03-23 16:16:09.544 916 1034 E WifiConfigStore: rewrite network history for "kathy"-WPA_PSK
03-23 16:16:09.580 916 1034 D IpReachabilityMonitor: watch: iface{wlan0/25}, v{5}, ntable=[192.168.1.254/NUD_NONE]
03-23 16:16:09.580 916 1034 D WifiStateMachine: Lost IP layer provisioning! was: {InterfaceName: wlan0 LinkAddresses: [fe80::fae0:79ff:fe68:4143/64,] Routes: [fe80::/64 -> :: wlan0,192.168.1.0/24 -> 0.0.0.0 wlan0,0.0.0.0/0 -> 192.168.1.254 wlan0,] DnsAddresses: [] Domains: attlocal.net MTU: 0 TcpBufferSizes: 524288,1048576,2097152,262144,524288,1048576} now: {InterfaceName: wlan0 LinkAddresses: [fe80::fae0:79ff:fe68:4143/64,] Routes: [fe80::/64 -> :: wlan0,192.168.1.0/24 -> 0.0.0.0 wlan0,0.0.0.0/0 -> 192.168.1.254 wlan0,] DnsAddresses: [] Domains: attlocal.net MTU: 0 TcpBufferSizes: 524288,1048576,2097152,262144,524288,1048576}
03-23 16:16:09.581 916 1034 E WifiConfigStore: SSID temp disabled for "kathy"-WPA_PSK had autoJoinStatus=0 self added false ephemeral false
03-23 16:16:09.582 916 1034 E WifiConfigStore: message=DHCP FAILURE
03-23 16:16:09.582 916 1034 E WifiConfigStore: blacklisted "kathy"-WPA_PSK to 0 due to IP config failures, count=1 disableReason=0 84:61:a0:6c:52:a0 ipfail=1
03-23 16:16:09.583 916 1036 D ConnectivityService: Setting Dns servers for network 102 to []
03-23 16:16:09.590 916 1036 I Nat464Xlat: Starting clatd on wlan0
03-23 16:16:09.591 24747 24747 D DHCP : ===== DHCP message:
03-23 16:16:09.591 24747 24747 D DHCP : op = BOOTREQUEST (1), htype = 1, hlen = 6, hops = 0
03-23 16:16:09.591 24747 24747 D DHCP : xid = 0xed2bcf00 secs = 0, flags = 0x8000 optlen = 14
03-23 16:16:09.591 24747 24747 D DHCP : ciaddr = 0.0.0.0
03-23 16:16:09.591 24747 24747 D DHCP : yiaddr = 0.0.0.0
03-23 16:16:09.591 24747 24747 D DHCP : siaddr = 0.0.0.0
03-23 16:16:09.591 24747 24747 D DHCP : giaddr = 0.0.0.0
03-23 16:16:09.591 24747 24747 D DHCP : chaddr = { f8 e0 79 68 41 43 }
03-23 16:16:09.591 24747 24747 D DHCP : sname = ''
03-23 16:16:09.591 24747 24747 D DHCP : file = ''
03-23 16:16:09.591 24747 24747 D DHCP : op 53 len 1 { 01 } discover
03-23 16:16:09.591 24747 24747 D DHCP : op 55 len 4 { 01 03 06 1c }
03-23 16:16:09.592 227 912 D ClatdController: starting clatd on wlan0
03-23 16:16:09.592 227 912 D ClatdController: clatd started on wlan0
03-23 16:16:09.621 1107 1107 I wpa_supplicant: wlan0: CTRL-EVENT-DISCONNECTED bssid=84:61:a0:6c:52:a0 reason=3 locally_generated=1
03-23 16:16:09.624 916 1034 D WifiStateMachine: WifiStateMachine: Leaving Connected state
03-23 16:16:09.624 916 1034 D IpReachabilityMonitor: clear: iface{wlan0/25}, v{6}, ntable=[]
03-23 16:16:09.624 916 1034 D WifiNative-HAL: stopRssiMonitoring, cmdId 0
03-23 16:16:09.625 916 1034 E WifiConfigStore: saveWifiConfigBSSID Setting BSSID for "kathy"-WPA_PSK to any
03-23 16:16:09.625 916 1034 E wifi_gbk2utf: g_pItemList is NULL
03-23 16:16:09.631 916 937 D Tethering: InitialState.processMessage what=4
03-23 16:16:09.632 1107 1107 I wpa_supplicant: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
03-23 16:16:09.633 916 937 D Tethering: sendTetherStateChangedBroadcast 0, 0, 0
03-23 16:16:09.644 916 1034 E native : do suspend true
03-23 16:16:09.646 916 6683 D DhcpClient: Clearing IP address
03-23 16:16:09.646 227 912 D CommandListener: Clearing all IP addresses on wlan0
03-23 16:16:09.647 227 912 D CommandListener: Setting iface cfg
03-23 16:16:09.684 916 1036 D ConnectivityService: notifyType IP_CHANGED for NetworkAgentInfo [WIFI () - 102]
03-23 16:16:09.686 916 1034 D WifiStateMachine: Start Disconnecting Watchdog 2
03-23 16:16:09.687 916 1034 D WifiNative-HAL: stopRssiMonitoring, cmdId 0
03-23 16:16:09.687 916 1034 E native : do suspend true
03-23 16:16:09.689 227 912 D CommandListener: Clearing all IP addresses on wlan0
03-23 16:16:09.711 916 1036 D ConnectivityService: NetworkAgentInfo [WIFI () - 102] EVENT_NETWORK_INFO_CHANGED, going from CONNECTED to DISCONNECTED
03-23 16:16:09.711 916 1036 D ConnectivityService: NetworkAgentInfo [WIFI () - 102] got DISCONNECTED, was satisfying 4
03-23 16:16:09.714 916 1034 D WifiNetworkAgent: NetworkAgent: NetworkAgent channel lost
03-23 16:16:09.733 916 1036 D ConnectivityService: notifyType LOST for NetworkAgentInfo [WIFI () - 102]
03-23 16:16:09.735 24757 24757 I clatd : Starting clat version 1.4 on wlan0 netid=102 mark=0xf0066
03-23 16:16:09.738 916 1036 I Nat464Xlat: Stopping clatd
03-23 16:16:09.739 227 912 D ClatdController: Stopping clatd pid=24757 on wlan0
03-23 16:16:09.588 24747 24747 I dhcptool: type=1400 audit(0.0:1385): avc: denied { write } for scontext=u:r:init:s0 tcontext=u:r:init:s0 tclass=packet_socket permissive=1
03-23 16:16:09.761 916 14278 D DhcpClient: Receive thread stopped
03-23 16:16:09.840 1911 728 I ClearcutLoggerApiImpl: disconnect managed GoogleApiClient
03-23 16:16:09.857 916 1723 I ProcessStatsService: Added stats: 2016-03-23-10-14-19, over +3h28m23s354ms
03-23 16:16:09.867 916 1723 I ProcessStatsService: Added stats: 2016-03-23-07-27-57, over +2h15m25s978ms
03-23 16:16:09.878 916 1723 I ProcessStatsService: Added stats: 2016-03-22-19-46-56, over +11h40m59s274ms
03-23 16:16:09.887 916 1723 I ProcessStatsService: Added stats: 2016-03-22-19-16-57, over +5m54s959ms
03-23 16:16:09.900 227 912 D ClatdController: clatd on wlan0 stopped
03-23 16:16:09.901 916 1036 D CSLegacyTypeTracker: Sending DISCONNECTED broadcast for type 1 NetworkAgentInfo [WIFI () - 102] isDefaultNetwork=true
03-23 16:16:09.901 916 1036 D ConnectivityService: sendStickyBroadcast: action=android.net.conn.CONNECTIVITY_CHANGE
03-23 16:16:09.905 2124 2124 D NetworkChangeNotifierAutoDetect: Network connectivity changed, type is: 6

Anyway, .. These are the lines that I'm thinking might be of interest:

And those lines eventually lead to a "state going from CONNECTED to DISCONNECTED". Well, kind of figures ;;)

I'll probably spend another half hour seeing if I can figure out why this is happening. "dhcpd.conf" seems configured OK, and the usual suspects for a dhcp connect seems OK. If I could figure out the usual "connect command" in "command line lingo for android", it would be easier to troubleshoot, but no luck so far. Usually I use something like "dhclient eth0/wlan0" to crank up the client, but apparently on android, it's another matter like possibly "dhcptool wlan0 {unknown param}" , etc. If anyone knows or sees anything in here, feel free to chime in with some help.

The approach I'm trying now is this: From the adb shell, I'm doing a ps (show list of ~100+ processes that're usually running) | grep -i dhc). So that's a search of all running processes and a simultaneous search for any containing the string "dhc*" (like dhcpd/dhcptool/dhcp/dhclient/whatever-else-starts-with-dhc*). I've got to crank up another phone and try the same thing to figure out what's missing. Until now (when I just forgot everything including my name) , I thought I recalled that dhcpd was a constantly running daemon, so the fact that I'm coming up with zip is interesting.

Edit 1: more testing from the router::

I logged into my router and thought it might be of interest to see what was happening during the so-called "logcat" events from the MotoX AFTER I'd killed the WiFi connection.

At the times when logcat showed (as above in the code section) it was trying to do something, which I'd have imagined would be "seen" by the router, the router registered no packets. So it seems likely that the MotoX isn't outputting anything when it claims it's trying to reconnect (and getting those errors). I guess that's no huge surprise..

When I went into wifi settings and told it to connect, the router firewall log came to life and the usual DHCP chatter came along and showed up, connecting the first time no problem.

Edit 2: Checked option to revert to the old version of DHCPCD (prior dhcp client from 5.1 era in developer options):

Not a success of any sort, in fact checking that option makes me think the earlier client isn't included. If I find that out to be true, I'll move the earlier client over the newer one myself, but I think the problem is prior to the client, as in wherever the client's intent is called.

Also: I unchecked that option, & rebooted, and since yesterday haven't been able to replicate the problem. I think it's a coincidence, but not sure yet. This is pretty hard to troubleshoot if I can't reproduce it ;;) // scratch that "can't reproduce it" stuff. I forgot that this is really just about reconnecting, not losing connection. I can reproduce it anytime just by manually disconnecting wifi.

edit 1: I tested at first with the stock kernel and next with tycoo kernel, which to me are indistinguishable from one another as they regard this networking problem.

Edit 2:: dhcpcd testing using pre-6.0.1 (5.1 in my case) android motox::

As I thought I recalled from my linux days, when wi-fi is enabled (not connected, just enabled), dhcpcd (/system/bin/dhcpcd) shows up as a constantly running daemon (is there another kind? ;;)) and that is a significant difference between 5.1 (or 6.0.0) and 6.0.1 (or the latest cm13 version we're all using). Without /system/bin/dhcpcd being present, there is never going to be a reconnect to wi-fi, period. I'll start looking there after I compare the syslogs which I've now got. I don't want to get anyone's hopes up since there is an issue open in the google codebase already and if they can't find it first, well, something is way off.

I'm hoping to get a bit of a clue by seeing how dhcpcd is kicked off during boot (likely from something in rc.local if it exists on android or in (/etc/init.d) via the boot process. It works that one time, never again.

Edit 3: Issue as in codebase (is closed but high-priority for some unknown reason):

https://code.google.com/p/android/i...tars Reporter Opened&groupby=&sort=&id=190667

Anyway: After I read that issue (152 posts + the very last one is mine asking them to reopen it or point us to where this issue is either continued, etc., then I also started to recall that wpa_supplicant could play a huge role in this sort of problem as well. I had completely forgot the Wi-Fi part of this bringing in other primary dependencies. Ah well. Been awhile since I looked at these sorts of things. More stuff to ignore from me to come no doubt.

Continuing to track things: This issue I mentioned above was apparently "fixed" (see comment 61 in the above link to the google bugbase). I'll list the pertinent comments:

If that's so: Then the next decent question (which I asked over on google's bug base) is: Where in the code is the fix or has it been released in any form to anyone, or is there at least a work-a-round. ? I think it might help if a bunch of you guys who are interested went over there and a) signed in b) starred the issue and c) left a comment. They may think this is a dead issue..