I am testing nbs technology on 2 devices: Redmi 9 and Oppo Reno 3. When Redmi discovers and Oppo do advertising, both devices find each other and successfully connect. However, when Oppo discovers and Redmi advertises, they cannot connect and throw Socket closed exception. What could be the problem?
Logs below:
2022-09-07 11:28:54.601 31648-4348/? I/NearbyConnections: Listening to visibility changes for client 119155262 [CONTEXT service_id=54 ]
2022-09-07 11:28:54.603 32312-32312/com.das2.accounting.mobileTest D/NearbyConnections: NFC discovery started.
2022-09-07 11:28:54.603 32312-32312/com.das2.accounting.mobileTest D/NearbyConnections: Invalidating dispatch state.
2022-09-07 11:28:54.603 32312-32312/com.das2.accounting.mobileTest D/NearbyConnections: Starting NFC dispatching.
2022-09-07 11:28:54.603 32312-32312/com.das2.accounting.mobileTest D/NearbyConnections: Cannot dispatch NFC events. NFC is not supported.
2022-09-07 11:28:54.716 1816-1816/? I/CompanionDeviceManagerService: onDeviceNearby(justAppeared, address = 18:54:CF:DD:AD:6A)
2022-09-07 11:28:54.793 31648-31648/? I/NearbyDiscovery: onAclChange: state=CONNECTED, device=XX:XX:XX:XX:AD:6A [CONTEXT service_id=49 ]
2022-09-07 11:28:54.797 31648-31802/? I/NearbyDiscovery: FastPair: lock scan rate if needed, device=XX:XX:XX:XX:AD:6A, bondState=12 [CONTEXT service_id=49 ]
2022-09-07 11:28:54.798 31648-31802/? I/NearbyDiscovery: FastPairScanner: isScreenOn=true, scanWithScreenOff=false, isLocationEnabled=true, disableLocationRequirement=true, isDiscoveryScanningEnabled=true, during24GhzWifiWarmingUpPeriod=false [CONTEXT service_id=49 ]
2022-09-07 11:28:54.804 31648-31802/? I/NearbyDiscovery: FastPairScanner: eventType=DOWNGRADE_FOR_ACL_CONNECTED, intReq=false, scanning=true, scanAllowed=true, bleEnabled=true, bleScanAvailable=true, lockScanRate=false [CONTEXT service_id=49 ]
2022-09-07 11:28:54.805 31648-31802/? I/NearbyDiscovery: FastPairScanner: Already in LOW_POWER_SCANNING scanning [CONTEXT service_id=49 ]
2022-09-07 11:28:54.805 31648-31802/? I/NearbyDiscovery: FastPairScanner: set recover event type, from=BLUETOOTH_ON, to=BLUETOOTH_ON [CONTEXT service_id=49 ]
2022-09-07 11:28:54.805 31648-4143/? I/NearbyDiscovery: FastPairBattery: No associated accountKey is found when query battery info, address:XX:XX:XX:XX:AD:6A [CONTEXT service_id=49 ]
2022-09-07 11:28:54.810 31648-4348/? I/NearbyMediums: Wifi LAN discovered service at 10.237.42.51 [CONTEXT service_id=54 ]
2022-09-07 11:28:54.810 31648-4348/? I/NearbyMediums: Found service I1hHTTNItboAAA on Wifi LAN. [CONTEXT service_id=54 ]
2022-09-07 11:28:54.811 31648-2126/? I/NearbyConnections: Found WifiLanServiceInfo I1hHTTNItboAAA (with EndpointId XGM3 / EndpointInfo [ 0x53 0x65 0x6e 0x64 0x65 0x72 ] / AP frequency 5745) [CONTEXT service_id=54 ]
2022-09-07 11:28:54.813 31648-2126/? I/NearbyConnections: ClientProxy(119155262) reporting onEndpointFound(XGM3) [CONTEXT service_id=54 ]
2022-09-07 11:28:54.815 31648-2126/? I/NearbyConnections: ClientProxy(119155262) reporting onEndpointDistanceChanged(XGM3, UNKNOWN) [CONTEXT service_id=54 ]
2022-09-07 11:28:54.816 31648-4348/? I/NearbyMediums: IP(/10.237.42.51) is reachable, took 4ms [CONTEXT service_id=54 ]
2022-09-07 11:28:54.819 31648-13460/? I/NearbyConnections: Client 119155262 requested a connection to endpoint XGM3. [CONTEXT service_id=54 ]
2022-09-07 11:28:54.821 31648-2126/? I/NearbyConnections: In requestConnection(), attempting to connect to endpoint XGM3 over mediums [WIFI_LAN, BLUETOOTH]. [CONTEXT service_id=54 ]
2022-09-07 11:28:54.831 31648-2126/? I/NearbyMediums: Bind Wifi LAN socket on network 122. [CONTEXT service_id=54 ]
2022-09-07 11:28:54.836 31648-2126/? I/NearbyMediums: Socket send buffer size: Requested 4194304 and returned 8388608 [CONTEXT service_id=54 ]
2022-09-07 11:28:54.837 31648-2126/? I/NearbyMediums: Socket receive buffer size: Requested 4194304 and returned 8388608 [CONTEXT service_id=54 ]
2022-09-07 11:28:54.837 31648-2126/? I/NearbyConnections: In requestConnection(), successfully created a WIFI_LAN EndpointChannel to endpoint XGM3 [CONTEXT service_id=54 ]
2022-09-07 11:28:54.838 31648-2126/? I/NearbyConnections: Generated local endpoint id LJMR for client 119155262 [CONTEXT service_id=54 ]
2022-09-07 11:28:54.868 31648-2126/? I/NearbyMediums: Querying usable channels is unsupported on the local device or unsupported on WIFI_BAND_5_GHZ_WITH_DFS of OP_MODE_WIFI_DIRECT_CLI. [CONTEXT service_id=54 ]
2022-09-07 11:28:54.871 31648-2126/? I/NearbyMediums: Querying usable channels is unsupported on the local device or unsupported on WIFI_BAND_24_GHZ of OP_MODE_WIFI_DIRECT_CLI. [CONTEXT service_id=54 ]
2022-09-07 11:28:54.873 31648-2126/? I/NearbyMediums: Querying usable channels is unsupported on the local device or unsupported on WIFI_BAND_5_GHZ_WITH_DFS of OP_MODE_TDLS. [CONTEXT service_id=54 ]
2022-09-07 11:28:54.875 31648-2126/? I/NearbyMediums: Querying usable channels is unsupported on the local device or unsupported on WIFI_BAND_24_GHZ of OP_MODE_TDLS. [CONTEXT service_id=54 ]
2022-09-07 11:28:54.877 31648-2126/? I/NearbyMediums: Querying usable channels is unsupported on the local device or unsupported on WIFI_BAND_5_GHZ_WITH_DFS of OP_MODE_WIFI_AWARE. [CONTEXT service_id=54 ]
2022-09-07 11:28:54.879 31648-2126/? I/NearbyMediums: Querying usable channels is unsupported on the local device or unsupported on WIFI_BAND_24_GHZ of OP_MODE_WIFI_AWARE. [CONTEXT service_id=54 ]
2022-09-07 11:28:54.881 31648-2126/? I/NearbyMediums: Querying usable channels is unsupported on the local device or unsupported on WIFI_BAND_5_GHZ_WITH_DFS of OP_MODE_STA. [CONTEXT service_id=54 ]
2022-09-07 11:28:54.883 31648-2126/? I/NearbyMediums: Querying usable channels is unsupported on the local device or unsupported on WIFI_BAND_24_GHZ of OP_MODE_STA. [CONTEXT service_id=54 ]
2022-09-07 11:28:54.884 31648-2126/? I/NearbyConnections: In requestConnection(), wrote ConnectionRequestFrame to endpoint XGM3 [CONTEXT service_id=54 ]
2022-09-07 11:28:57.075 31648-4953/? I/NearbyConnections: Found BluetoothDeviceName I1hHTTNItboAAAAAAAAABlNlbmRlcg (with EndpointId XGM3 and EndpointInfo [ 0x53 0x65 0x6e 0x64 0x65 0x72 ]) [CONTEXT service_id=54 ]
2022-09-07 11:28:57.079 31648-4953/? I/NearbyConnections: ClientProxy(119155262) ignoring onEndpointDistanceChanged(XGM3, UNKNOWN), because this distance has already been reported [CONTEXT service_id=54 ]
2022-09-07 11:28:57.081 31648-4953/? I/NearbyConnections: Found BluetoothDeviceName I1hHTTNItboAAAAAAAAABlNlbmRlcg (with EndpointId XGM3 and EndpointInfo [ 0x53 0x65 0x6e 0x64 0x65 0x72 ]) [CONTEXT service_id=54 ]
2022-09-07 11:28:57.082 31648-4953/? I/NearbyConnections: ClientProxy(119155262) ignoring onEndpointDistanceChanged(XGM3, UNKNOWN), because this distance has already been reported [CONTEXT service_id=54 ]
2022-09-07 11:28:57.615 31648-31505/? I/NearbyMediums: Ignore GATT advertisement and wait for extended advertisement. [CONTEXT service_id=54 ]
2022-09-07 11:28:58.707 31648-31505/? I/NearbyMediums: Ignore GATT advertisement and wait for extended advertisement. [CONTEXT service_id=54 ]
2022-09-07 11:29:08.449 31648-4953/? I/NearbyMediums: Wifi LAN discovered service at 10.237.42.51 [CONTEXT service_id=54 ]
2022-09-07 11:29:08.449 31648-4953/? I/NearbyMediums: Found service I1hHTTNItboAAA on Wifi LAN. [CONTEXT service_id=54 ]
2022-09-07 11:29:08.450 31648-2126/? I/NearbyConnections: Found WifiLanServiceInfo I1hHTTNItboAAA (with EndpointId XGM3 / EndpointInfo [ 0x53 0x65 0x6e 0x64 0x65 0x72 ] / AP frequency 5745) [CONTEXT service_id=54 ]
2022-09-07 11:29:08.455 31648-2126/? I/NearbyConnections: ClientProxy(119155262) ignoring onEndpointDistanceChanged(XGM3, UNKNOWN), because this distance has already been reported [CONTEXT service_id=54 ]
2022-09-07 11:29:08.560 31648-2126/? I/NearbyMediums: Matched service ID FW15555 to GATT advertisement BleAdvertisement { version=2, socketVersion=2, serviceIdHash=[ 0x48 0xb5 0xba ], data=[ 0x23 0x48 0xb5 0xba 0x58 0x47 0x4d 0x33 0x06 0x53 0x65 0x6e 0x64 0x65 0x72 0x9c 0x5a 0x81 0x07 0x03 0x79 0x00 0x00 ], deviceToken=[ 0xf7 0x11 ] }. [CONTEXT service_id=54 ]
2022-09-07 11:29:08.561 31648-31505/? I/NearbyConnections: Found BleAdvertisement [ 0x23 0x48 0xb5 0xba 0x58 0x47 0x4d 0x33 0x06 0x53 0x65 0x6e 0x64 0x65 0x72 0x9c 0x5a 0x81 0x07 0x03 0x79 0x00 0x00 ] (with EndpointId XGM3 and EndpointInfo [ 0x53 0x65 0x6e 0x64 0x65 0x72 ]) [CONTEXT service_id=54 ]
2022-09-07 11:29:08.562 31648-31505/? I/NearbyConnections: ClientProxy(119155262) ignoring onEndpointDistanceChanged(XGM3, UNKNOWN), because this distance has already been reported [CONTEXT service_id=54 ]
2022-09-07 11:29:09.290 31648-2126/? I/NearbyMediums: Matched service ID FW15555 to GATT advertisement BleAdvertisement { version=2, socketVersion=2, serviceIdHash=[ 0x48 0xb5 0xba ], data=[ 0x23 0x48 0xb5 0xba 0x58 0x47 0x4d 0x33 0x06 0x53 0x65 0x6e 0x64 0x65 0x72 0x9c 0x5a 0x81 0x07 0x03 0x79 0x00 0x00 ], deviceToken=[ 0xf7 0x11 ] }. [CONTEXT service_id=54 ]
2022-09-07 11:29:09.483 31648-4953/? I/NearbyMediums: Ping IP(/10.237.42.51) timeout, took 1032ms [CONTEXT service_id=54 ]
2022-09-07 11:29:09.886 31648-4953/? I/NearbyConnections: Timing out encryption for client 119155262 to endpoint XGM3 after 15000 ms [CONTEXT service_id=54 ]
2022-09-07 11:29:09.888 31648-1141/? E/NearbyConnections: In startClient(), UKEY2 failed with endpoint XGM3 [CONTEXT service_id=54 ]
java.net.SocketException: Socket closed
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:118)
at java.net.SocketInputStream.read(SocketInputStream.java:173)
at java.net.SocketInputStream.read(SocketInputStream.java:143)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:248)
at java.io.BufferedInputStream.read1(BufferedInputStream.java:288)
at java.io.BufferedInputStream.read(BufferedInputStream.java:347)
at java.io.DataInputStream.readFully(DataInputStream.java:203)
at java.io.DataInputStream.readInt(DataInputStream.java:394)
at ascu.x(:com.google.android.gms@222615045@22.26.15 (190408-461192076):1)
at ascu.w(:com.google.android.gms@222615045@22.26.15 (190408-461192076):2)
at ascu.v(:com.google.android.gms@222615045@22.26.15 (190408-461192076):0)
at asez.run(:com.google.android.gms@222615045@22.26.15 (190408-461192076):7)
at arwc.run(:com.google.android.gms@222615045@22.26.15 (190408-461192076):3)
at xot.c(:com.google.android.gms@222615045@22.26.15 (190408-461192076):6)
at xot.run(:com.google.android.gms@222615045@22.26.15 (190408-461192076):7)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1137)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:637)
at xty.run(:com.google.android.gms@222615045@22.26.15 (190408-461192076):0)
at java.lang.Thread.run(Thread.java:1012)
2022-09-07 11:29:09.893 31648-2126/? W/NearbyMediums: Failed to get socket send buffer size. [CONTEXT service_id=54 ]
java.net.SocketException: Socket is closed
at java.net.Socket.getSendBufferSize(Socket.java:1277)
at awas.b(:com.google.android.gms@222615045@22.26.15 (190408-461192076):1)
at ascu.d(:com.google.android.gms@222615045@22.26.15 (190408-461192076):0)
at asho.a(:com.google.android.gms@222615045@22.26.15 (190408-461192076):14)
at asnc.v(:com.google.android.gms@222615045@22.26.15 (190408-461192076):13)
at asnc.C(:com.google.android.gms@222615045@22.26.15 (190408-461192076):1)
at askg.run(:com.google.android.gms@222615045@22.26.15 (190408-461192076):6)
at arwc.run(:com.google.android.gms@222615045@22.26.15 (190408-461192076):3)
at xot.c(:com.google.android.gms@222615045@22.26.15 (190408-461192076):6)
at xot.run(:com.google.android.gms@222615045@22.26.15 (190408-461192076):7)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1137)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:637)
at xty.run(:com.google.android.gms@222615045@22.26.15 (190408-461192076):0)
at java.lang.Thread.run(Thread.java:1012)
2022-09-07 11:29:09.894 31648-4953/? I/Nearby: Successfully shutdown executor BaseEndpointChannel.writeExecutor. [CONTEXT service_id=49 ]
2022-09-07 11:29:09.894 31648-4953/? I/Nearby: Successfully shutdown executor BaseEndpointChannel.readExecutor. [CONTEXT service_id=49 ]
2022-09-07 11:29:09.895 31648-2126/? W/NearbyMediums: Failed to get socket receive buffer size. [CONTEXT service_id=54 ]
java.net.SocketException: Socket is closed
at java.net.Socket.getReceiveBufferSize(Socket.java:1351)
at awas.a(:com.google.android.gms@222615045@22.26.15 (190408-461192076):1)
at ascu.c(:com.google.android.gms@222615045@22.26.15 (190408-461192076):0)
at asho.a(:com.google.android.gms@222615045@22.26.15 (190408-461192076):14)
at asnc.v(:com.google.android.gms@222615045@22.26.15 (190408-461192076):13)
at asnc.C(:com.google.android.gms@222615045@22.26.15 (190408-461192076):1)
at askg.run(:com.google.android.gms@222615045@22.26.15 (190408-461192076):6)
at arwc.run(:com.google.android.gms@222615045@22.26.15 (190408-461192076):3)
at xot.c(:com.google.android.gms@222615045@22.26.15 (190408-461192076):6)
at xot.run(:com.google.android.gms@222615045@22.26.15 (190408-461192076):7)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1137)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:637)
at xty.run(:com.google.android.gms@222615045@22.26.15 (190408-461192076):0)
at java.lang.Thread.run(Thread.java:1012)
2022-09-07 11:29:09.900 31648-2126/? I/NearbyConnections: In requestConnection(), given unknown endpoint Q0MX [CONTEXT service_id=54 ]