BTEvents.READ callback with latency

[eipporko]

Mobile Device Environment

• Device: Xiaomi Mi A3 & Samsung Galaxy Tab A
• OS: API 28

Application Environment

• React Native version: 0.63.1
• RN Bluetooth Classic version: 0.10.9

Describe the bug Handling data received by BTEvents.READ. I discovered that the data is processed with a certain delay (almost 1 second) and the data does not arrive in the same amount of messages per second as that sent by the device. Finally, after a certain time the listener stops processing anything.

To Reproduce Steps to reproduce the behavior:

1. Add the listener in componentDidMount() and define the function to handling the data

handleRead = data => {
    console.log(data.data);
    this.setState({sensorValue: data.data});
};

componentDidMount() {
...

this.onRead = RNBluetoothClassic.addListener(
      BTEvents.READ,
      this.handleRead,
      this
    );

...
}

2. Connect to the device
3. See the data in the device and the output log

Expected behavior Receive data as close as possible to real time and never stop of receive data.

Screenshots Screenshoot of the data received by the bluetooth serial terminal app

[kenjdavidson]

There are two possible issues here:

1. Is that there is a 500ms timeout included in the Java native code, I don't know why it was put there but it is a hold over from the original implementation which I forked and modified. I haven't had a chance to add the ConnectionConfiguration that I had planned yet. But this timeout will eventually be customizable (most of the Forks of this project actually remove the timeout).

2. You're using setState({data}) which is not linear. I'm assuming that the Terminal app (which I also use, is native and not react native) therefore it has much better performance for output. If set state is called too quickly, it is lumped and only the last setState will be updated. https://reactjs.org/docs/state-and-lifecycle.html#state-updates-may-be-asynchronous

With regards to the issue of stopping listening all together, that is really weird and may be something that I can look into. The negative here is, the only two devices I have are:

• Barcode scanner
• microchip scanner

which are pretty low data devices. I'd need to find some other way of testing something with higher data.

If you're using this module for time sensitive functionality, you may be out of luck, you may want to use a more customized native module that allows you to have finer control over the data stream, or use an alternate to setState.

[eipporko]

I tried again, commenting the setState({data}) and only writting the data in the output console log. I shared some extract of the log and I mark the discontinuities that I found, I hope that could be helpful.

react-native-bluetooth-classic.log

[kenjdavidson]

Thanks, I have some questions though, and I'm sorry I don't really understand what the problem is (finer detail), you're sample data doesn't make sense to me, the numbers are neither:

• In order
• nor unique

so how exactly are you sure that the first #56 is a discontinuity? Is the 56:

• Not supposed to be there?
• Supposed to be in a different order
• Etc.

Could you provide details on:

• What your device is?
• What these values are which it's sending?
• How often they are being sent?

If I'm going to replicate it, I'm going to need to know how and what to replicate. Right now I just see a stream of integers/strings with no order or uniqueness, and no way of validating.

[eipporko]

The device is an Arduino with a HC-06 bluetooth module and a pressure sensor which sends the value readed each 25ms. I understand that there was a discontinuity, because the gap between 2 samples it was much higher than 25ms.

In the log are shown 2 timestamp.

• The first one in when the data is processed by the handleRead method, listening to the event BTEvents.READ
• The second timestamp is added by BluetoothMessage class when is readed.

So because of that I understand that the latency can be measured with the diference between the first and the second timestamp.

I don't know why the messages are not in order, but probably the sendEvent method doesn't guarantee this order??

I you pay attention in the second timestamp, although some events are processed at the same time, the data was readed in different time instances.

[kenjdavidson]

The discontinuities look like they are at pretty regular intervals, this is probably due to the SLEEP in the native read method. What happens is:

• Wait for data
• Reads data into Buffer
• Reads buffer from start to end looking for delimiter(s)
• Each delimiter is then sent in an individual message
• Sleep
• Loop

I think you're seeing the reason why almost all the forks of this project REMOVE the sleep, or reduce it to a smaller value. I just haven't gotten around to allowing for further customization of the connection, there are a number of changes required for this:

• Delimiter
• Size
• Sleep
• Etc

that I need to go through all the Forks and pull their changes into a ConnectionProperties object, so that it's more configurable.

I'm leaning towards the sleep being your enemy, specifically with this kind of data.

[eipporko]

I just tried to increment the delay between messages in the Arduino project to 100ms and I'm still detecting that periodically discontinuity, so probably you are right and that sleep is my enemy.

What could be the reason about this Thread.sleep(500)?? Sounds like a magic number

I'm going to try to remove this sleep and look if something breaks. :)

[kenjdavidson]

It's 100% a magic number, that is just a hold over from the original project react-native-bluetooth-serial. If you look at almost all the forks, they've removed the sleep - so I assume this poses no problems for them. I don't really think it needs to be there, I just haven't gotten around to removing it since the reason I reworked the module doesn't require this type of speed (it's a manual communication process).

Once winter comes, and I don't spend my evenings outside, I'll start working on all these enhancements. But outside is always > computers.

[eipporko]

I removed that sleep and It works! xD Now I have the samples with a good latency and responds quickly.

Notice that my idea of measuring the latency with the difference beetween the first timestamp and the second one was wrong, probably the first timestamp is written by my computer and the second one is my android device =)

The only problem that I found now is that after a while (1 minute) , I stops of receiving any message and I need to reconnect to the device in order to start to receive data again. And I don't know if really there was a disconnection, because I didn't receive any BTEvents.BLUETOOTH_DISCONNECTED event.

Don't worry, I understand your preference with being outside, I'm from a very rainy place (Galicia) and when there is a minimum opportunity to enjoy the sun is an moral obligation. :)

[kenjdavidson]

Nice! If you're not getting a BLUETOOTH_DISCONNECTED then I'm not sure what's up. If you debug it definitely update the ticket (leaving open) with your findings and we should definitely get it fixed. There are a number of places where a message could be dropped, or I could be missing an instance of a disconnect and not sending that event.

Do you have your arduino code posted? I have a couple bluetooth modules laying around and could probably replicate the issue.

[eipporko]

I'm gonna take a look and I tell you if I found something. Also I'm gonna compare this behaviour with the obtained with the Serial Bluetooth Terminal App, because maybe is a problem related with the arduino side instead of Android :)

I have the arduino project posted, you can find it here https://github.com/eipporko/folimetro

[kenjdavidson]

Sounds like a plan, the BluetoothClassicExample is a react native version of the Serial Bluetooth Terminal App, which I also use for comparing communication with our hardware. I appreciate all the details you've been providing, this project has definitely taken off more than I anticipated (specifically since the purpose of it was for IOS, not even Android features).

[eipporko]

Sorry about the delay in this response but I was doing some kind of research about the problem related with stop receiving data from the bluetooth device.

I found the next:

• I was testing with different Android 10 devices (Xiaomi Mi A2, Xiaomi Mi A3 & OnePlus 5T)
• The only one where I found this weird behaviour was in the Xiaomi Mi A3.
• Before a while (not always at the same time) the app stops of receiving data.

Checking the log with adb logcat I found that after the next messages, the application stops of receiving data from the InputStream.

08-20 14:17:41.175   683  2902 I [email protected]_handler: DeviceSleep: TX Awake, Sending SLEEP_IND
08-20 14:17:41.175   683  2902 D [email protected]_handler: SerialClockVote: vote for UART CLK OFF
08-20 14:17:41.326   683  2755 D [email protected]_lock: Release wakelock is released 

The thread related with the task of reading data from the InputStream, gets stuck waiting for input data available to write in the buffer. You can find this process here->bluetooth/RNBluetoothClassicService.java:468

At first I thought that could be something related with the socket between android and the bluetooth device, but despite not been receiving data if I turn off the bluetooth device the thread which was stuck waiting for data, gets an exception and stops gracefully showing in the log the next message Disconnected - was it cancelled? false

So seems that the socket is open and working but something related with the communication protocol between the Android and the Bluetooth device is wrong.

[kenjdavidson]

Thanks for the update, I still will look at it at some point - since if you're using the native app we discussed (Terminal) and it doesn't have this problem, then it may have to do with:

• The method in which the library connects to the device, there are numerous to choose from. I'm hoping to have those customizable in v11

Unless the issue exists in the native app (Terminal), but you said it was not. Specifically if the issue is that #read() method is not returning, there isn't going to be much I can do with it - although maybe if there is a timeout and it retries later it might work?

[eipporko]

Maybe I explained it wrong, but the behaviour with the native app (Terminal) is the same, when the logcat shown the messages commented before the application stops to receive data.

Probably is something related with the OS, but I don't know if there is any way to manage this and avoid this behaviour.

08-20 17:23:46.120   683  2902 I [email protected]_handler: DeviceSleep: TX Awake, Sending SLEEP_IND
08-20 17:23:46.121   683  2902 D [email protected]_handler: SerialClockVote: vote for UART CLK OFF
08-20 17:23:46.282   683  2755 D [email protected]_lock: Release wakelock is released