I'm trying to use the new Android Nearby Connections v2.0 API with the P2P_CLUSTER connection strategy. The following problem (in which both devices request connections, but don't successfully connect) seems to occur on a variety of devices running Android K-N. Sometimes the code gets a successful persistent connection... Sometimes it doesn't.
In this scenario, both sides are advertising and discovering, both sides discover each other, and both sides send connection requests (but connection is not initiated). It's difficult to make this situation happen reliably with a specific test case, but it does happen.
Using Android Monitor, I've captured detailed information about what this scenario looks like from one side, and listed the sequence of events below. In this particular session, the device that I was monitoring was a very cheap KitKat phone, and the remote endpoint was a Samsung Lollipop tablet (in case that's relevant).
- The remote node is discovered, and we issue
requestConnection
Immediately afterward, Android Monitor shows this error:
09-28 11:49:38.706 17321-17823/? E/NearbyConnections: In startClient(), UKEY2 failed with endpoint AqXW
java.io.IOException: bt socket closed, read return: -1
at android.bluetooth.BluetoothSocket.read(BluetoothSocket.java:647)
at android.bluetooth.BluetoothInputStream.read(BluetoothInputStream.java:96)
at java.io.InputStream.read(InputStream.java:162)
at java.io.BufferedInputStream.fillbuf(BufferedInputStream.java:149)
at java.io.BufferedInputStream.read(BufferedInputStream.java:295)
at libcore.io.Streams.readFully(Streams.java:81)
at java.io.DataInputStream.readInt(DataInputStream.java:103)
at xkj.c(:com.google.android.gms@11509230:1)
at xkg.run(:com.google.android.gms@11509230:8)
at mng.run(:com.google.android.gms@11509230:25)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
at mso.run(:com.google.android.gms@11509230)
at java.lang.Thread.run(Thread.java:818)
Immediately after that, it hits the requestConnection's ResultCallback, with STATUS_ENDPOINT_IO_ERROR (8012).
- Next, because the
requestConnection returned an error, we stop discovery, wait 3 seconds, and then start discovery again.
The next trace message after we restart discovery is this one from NearbyConnections:
09-28 11:49:46.333 17321-17412/? E/NearbyConnections: onIncomingConnection() for client 308946494 failed to initialize the connection with IkFxWFf_F-sAAAAAAAAAHHA_I2pIK25WaixTQEZSNHtVbmtub3duIFVzZXI
java.io.IOException: Failed to read ConnectionRequestFrame
at xjj.a(:com.google.android.gms@11509230:61)
at xlr.run(:com.google.android.gms@11509230:12)
at mng.run(:com.google.android.gms@11509230:25)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
at mso.run(:com.google.android.gms@11509230)
at java.lang.Thread.run(Thread.java:818)
Caused by: java.io.IOException: bt socket closed, read return: -1
at android.bluetooth.BluetoothSocket.read(BluetoothSocket.java:647)
at android.bluetooth.BluetoothInputStream.read(BluetoothInputStream.java:96)
at java.io.InputStream.read(InputStream.java:162)
at java.io.BufferedInputStream.fillbuf(BufferedInputStream.java:149)
at java.io.BufferedInputStream.read(BufferedInputStream.java:295)
at libcore.io.Streams.readFully(Streams.java:81)
at java.io.DataInputStream.readInt(DataInputStream.java:103)
at xkj.c(:com.google.android.gms@11509230:1)
at xjj.a(:com.google.android.gms@11509230:56)
at xlr.run(:com.google.android.gms@11509230:12)?
at mng.run(:com.google.android.gms@11509230:25)?
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)?
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)?
at mso.run(:com.google.android.gms@11509230)?
at java.lang.Thread.run(Thread.java:818)
I'm guessing that the above error was triggered from a requestConnection from the other side? And if we hadn't had that error, it would have gone to my onConnectionInitiated callback? (Just to clarify: It did not hit my onConnectionInitiated callback.)
Next, I once again discover the other node, and requestConnection once more.
Immediately after this, I see the following (different) error message from NearbyConnections:
09-28 11:51:14.639 17321-17412/? E/NearbyConnections: sendConnectionRequest() for client 308946494 failed to initialize the connection with endpoint AqXW
xjx: In connectImpl(), failed to connect to Bluetooth device 28:BE:03:0C:F1:5B for endpoint AqXW
at xlo.a(:com.google.android.gms@11509230:126)
at xjs.run(:com.google.android.gms@11509230:12)
at mng.run(:com.google.android.gms@11509230:25)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
at mso.run(:com.google.android.gms@11509230)
at java.lang.Thread.run(Thread.java:818)
Next, we hit the requestConnection's ResultCallback with STATUS_BLUETOOTH_ERROR (8007)
After this, I saw the devices connect then auto-disconnect, which repeated several times. They never did get a successful persistent connection, although I've seen this happen after a bunch of errors.
See Question&Answers more detail:
os 与恶龙缠斗过久,自身亦成为恶龙；凝视深渊过久,深渊将回以凝视…
