Connection upgrade failure on Lenovo Tab M10 leads to constant disconnection

[sarbogast]

I am developing an app for music bands where musicians can connect to a conductor's tablet, even when there is no internet connection in a basement or something like that. I am using Google Nearby Connections in a STAR strategy, using Flutter but going through version 19.0.0 of Google Nearby and un up-to-date Google Play Services on a couple of Lenovo Tab M10s.

I am testing my application in a setup where none of the tablets are connected to the internet, but Wifi is enabled on both, as well as bluetooth. The initial connection from the musician tablet to the conductor tablet works great, and they are even able to exchange payloads. But after a few seconds, the conductor (the hub in the star) disconnects without the user doing anything, and so all the spokes disconnect as well. I have made it so that when spokes receive the disconnection callback, they immediately try to reconnect to the same endpoint, and sometimes it works, sometimes it doesn't, but it never lasts, because soon enough, the hub disconnects again.

When we test with other devices, or with an internet connection, it seems to work fine. So my working hypothesis is that it's a hardware issue, that some tablets just don't support the wifi hotspot configuration properly and the connection upgrade fails or something, which seems to be confirmed by this logcat extract:

2023-10-13 10:09:48.346  1791-15556 NearbyMediums           com.google.android.gms.persistent    E  Failed to start a Wifi hotspot for service com.example.myapp
2023-10-13 10:09:48.346  1014-1014  UnisocWifiService       system_server                        D  action = android.net.wifi.WIFI_STATE_CHANGED
2023-10-13 10:09:48.346  1014-1014  Looper                  system_server                        W  Drained
2023-10-13 10:09:48.347  1367-1367  StatusBarSignalPolicy   com.android.systemui                 D  WifiIconState(resId=17302885, visible=true, dualWifiVisible=false)
2023-10-13 10:09:48.348  1791-15707 NearbyMediums           com.google.android.gms.persistent    E  There's no Direct hotspot to stop when the Wi-Fi Direct channel disconnected for service com.example.myapp.
2023-10-13 10:09:48.348  1791-15556 NearbyConnections       com.google.android.gms.persistent    E  BandwidthUpgradeManager couldn't complete the upgrade for endpoint WNI4 because it failed to initialize the BANDWIDTH_UPGRADE_NEGOTIATION.UPGRADE_PATH_AVAILABLE OfflineFrame. [CONTEXT service_id=54 ]
                                                                                                    bjmd: WifiHotspotBandwidthUpgradeMedium couldn't complete the Wifi upgrade for endpoint WNI4 because it failed to start a Wifi hotspot.
                                                                                                    	at bjwg.d(:com.google.android.gms@233717044@23.37.17 (190400-570218080):318)
                                                                                                    	at bjma.run(:com.google.android.gms@233717044@23.37.17 (190400-570218080):563)
                                                                                                    	at bjdt.run(:com.google.android.gms@233717044@23.37.17 (190400-570218080):15)
                                                                                                    	at ahzo.c(:com.google.android.gms@233717044@23.37.17 (190400-570218080):50)
                                                                                                    	at ahzo.run(:com.google.android.gms@233717044@23.37.17 (190400-570218080):97)
                                                                                                    	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
                                                                                                    	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
                                                                                                    	at aiet.run(:com.google.android.gms@233717044@23.37.17 (190400-570218080):8)
                                                                                                    	at java.lang.Thread.run(Thread.java:1012)
2023-10-13 10:09:48.349  1791-15556 NearbyMediums           com.google.android.gms.persistent    I  Cannot disconnect from the Wifi hotspot when it was never connected.
2023-10-13 10:09:48.349  1791-15556 NearbyConnections       com.google.android.gms.persistent    I  [BandwidthUpgradeProtocol] Remove upgrading medium WIFI_HOTSPOT for WNI4
2023-10-13 10:09:48.350  1791-15556 NearbyConnections       com.google.android.gms.persistent    I  [BandwidthUpgradeProtocol] Fallback or reset BandwidthUpgradeState because the next medium is the same with the connected one for WNI4.
2023-10-13 10:09:48.350  1791-15556 NearbyConnections       com.google.android.gms.persistent    I  [BandwidthUpgradeProtocol] The next medium is WIFI_DIRECT on BANDWIDTH_24_GHZ for WNI4
2023-10-13 10:09:48.350  1791-15556 NearbyConnections       com.google.android.gms.persistent    I  [BandwidthUpgradeProtocol] Set upgrading medium WIFI_DIRECT for WNI4
2023-10-13 10:09:48.351  1791-15556 NearbyConnections       com.google.android.gms.persistent    I  Retry bandwidth upgrade after 2000 ms
2023-10-13 10:09:48.352  1014-1154  AppOps                  system_server                        D  noteOperation() called with: code = [1], uid = [10127], packageName = [com.google.android.gms], attributionTag = [nearby_connections], shouldCollectAsyncNotedOp = [true], message = [android.app.AppOpsManager.noteOp(AppOpsManager.java:8307)
                                                                                                    com.android.server.wifi.util.WifiPermissionsUtil.noteAppOpAllowed(WifiPermissionsUtil.java:455)
                                                                                                    com.android.server.wifi.util.WifiPermissionsUtil.checkCallersLocationPermission(WifiPermissionsUtil.java:164)
                                                                                                    com.android.server.wifi.util.WifiPermissionsUtil.checkCanAccessWifiDirect(WifiPermissionsUtil.java:393)
                                                                                                    com.android.server.wifi.p2p.WifiP2pServiceImpl$P2pStateMachine$DefaultState.processMessage(WifiP2pServiceImpl.java:1196)
                                                                                                    com.android.wifi.x.com.android.internal.util.StateMachine$SmHandler.processMsg(StateMachine.java:993)
                                                                                                    ], shouldCollectMessage = [true]
2023-10-13 10:09:48.354  1014-1508  PowerController.RecogA  system_server                        D  packageName:com.google.android.gms mFgEvent:APP_COMPONENT_USED mLastTimeFgEventChanged:7805746 mLastLaunchTime:0 mProcState:PROCESS_STATE_CACHED_EMPTY mLastTimeProcStateChanged:0 mNotificationState:0 mLastTimeNotificationStateChanged:0 mAudioState:0 mLastTimeAudioStateChanged:0 mRequestGps:true mAvoidConstraintGps:false mBehaviorType:0 mScreenOn:true mLastTimeScreenStateChanged:0 mLastBgTime:0 mFgDuration:0 mAudioDuration:0 mBgAudioDuration:0 mHasNoClearNotificationWhenNavi:false
2023-10-13 10:09:48.354  1791-15556 NearbyMediums           com.google.android.gms.persistent    I  Failed to remove group for WIFI_DIRECT because no group was found.
2023-10-13 10:09:48.355  1014-1154  WifiP2pService          system_server                        D  Remove client - com.google.android.gms
2023-10-13 10:09:48.356  1791-1791  NearbyMediums           com.google.android.gms.persistent    I  WiFi Direct channel has disconnected.
2023-10-13 10:09:48.357  1791-15556 NearbyMediums           com.google.android.gms.persistent    I  Closed WiFi Direct channel.
2023-10-13 10:09:48.357  1791-15556 NearbyMediums           com.google.android.gms.persistent    I  Successfully stopped WiFi Direct group for service com.example.myapp
2023-10-13 10:09:48.357  1791-15707 NearbyMediums           com.google.android.gms.persistent    I  Closed WiFi Direct channel.
2023-10-13 10:09:48.357  1791-15556 NearbyMediums           com.google.android.gms.persistent    I  Stopped accepting WiFi Direct connections for service com.example.myapp.
2023-10-13 10:09:48.357  1791-15556 NearbyConnections       com.google.android.gms.persistent    I  [BandwidthUpgradeProtocol] Remove upgrading medium WIFI_DIRECT for 832G
2023-10-13 10:09:48.357  1791-15556 NearbyConnections       com.google.android.gms.persistent    I  [BandwidthUpgradeProtocol] Remove [BandwidthUpgradeState] 6GHz Mediums: [], 5GHz Mediums: [], 2.4GHz Mediums: [WIFI_DIRECT, WIFI_HOTSPOT, BLUETOOTH], [Initial Bandwidth: BANDWIDTH_24_GHZ][Current Bandwidth: BANDWIDTH_24_GHZ][Index: 0] for 832G
2023-10-13 10:09:48.357  1791-15538 NearbyMediums           com.google.android.gms.persistent    E  MEDIUM_ERROR [SYSTEM][WIFI_DIRECT][START_LISTENING_INCOMING_CONNECTION][ACCEPT_CONNECTION_FAILED][SOCKET_CLOSED], Service ID : com.example.myapp
2023-10-13 10:09:48.357  1791-15538 NearbyMediums           com.google.android.gms.persistent    E  Extra Sensitive/PII message : Socket closed
2023-10-13 10:09:48.358  1014-3167  WifiP2pService          system_server                        W  close(): no death recipient for binder
2023-10-13 10:09:48.359  7805-7805  nearby_connections      usap64                               D  ad.onDisconnected

But before I tell that to my customer, I would like to be sure.

Is my diagnosis correct? Can it be a hardware issue (we seem to have a similar issue with a Samsung Galaxy Tab S9)? If not, what else can it be and how can I troubleshoot this?

[johnsonlu072]

Is it possible to provide bugreports from both sides (advertiser and discoverer)?

[sarbogast]

What do you mean by that? The logcat extract I provided in the original issue is on the advertiser side, that seems to cause the disconnection, so all that the discoverer gets is a disconnection from the advertiser and that's all. The question is to understand why the advertiser disconnects.

[Xlythe]

If you can grab bug reports from both devices, it'll help us better understand the cause of the disconnection. Beyond just the logcat snippet, bug reports include a system dump of the system and some other interesting logs. The other adb commands below will also enable some logging that's off by default.

# To increase log buffer
adb logcat -G 32M

# To enable WiFi verbose logging
adb shell cmd wifi set-verbose-logging enabled

# To enable BT HCI logs
adb shell setprop persist.bluetooth.btsnooplogmode full
adb shell device_config put bluetooth INIT_logging_debug_enabled_for_all true
adb shell svc bluetooth disable
adb shell svc bluetooth enable

# To take a bugreport
adb bugreport

From just a glance at what you've pasted, it looks like when it tries to host WiFi Direct on 2.4GHz (after 5GHz fails), it causes interference with the Bluetooth connection. But it's hard to tell if this is caused by a 3rd device failing to upgrade and accidentally taking the entire hotspot down with it, or if there's an ongoing WiFi or Bluetooth scan that may be causing interference, or if it's as you said there's a hardware defect with this device.