2

I have a write function which basically add data to queue and sends data every 500ms and i have used couple of setTimeouts to write data as below. And Analysing logs i suspsect setTimeout has been called twice, i want to know is it even possible? and what could be the possible fix?


import BleManager from 'react-native-ble-manager';

const BleManagerModule = NativeModules.BleManager;
const bleManagerEmitter = new NativeEventEmitter(BleManagerModule);

class bleHandler {
constructor() {
    this.writeQueue = [];
    bleManagerEmitter.addListener('BleManagerDidUpdateValueForCharacteristic', this.handleUpdateValueForCharacteristic);
}

//this function will be called when ble receives data from peripheral.
handleUpdateValueForCharacteristic(data){
   // do something with data
   //send ack that data is received.
   this.writeData("AB:CD:EF:GH:IJ", " Some Important Message text ");
}

 writeData(peripheralID, data) {
    console.log("Adding data to Queue " + data);
    if (this.writeQueue.length == 0) {
      this.writeQueue.push(data);
      setTimeout(() => this.sendData(peripheralID, data), 500);
    } else
      this.writeQueue.push(data);

    console.log("New Queue Length = " + this.writeQueue.length);
  }

  sendData = (peripheralID, data) => {
    if (data.length > 0 && peripheralID && this.writeQueue.length > 0) {
      var byteBuf = this.formatData(data);
console.log("============" + slicedData + " and length = " + slicedData.length + " at Date = " + new Date().valueOf());
console.log("Writing Message : " + byteBuf );
      this.handleWriteWithoutResponse(peripheralID, UUID, CHAR, byteBuf).then(() => {
        console.log("success writing data ");

        data = data.substring(PACKET_SIZE - 5);
        if (data.length > 0) {
          setTimeout(() => {
            this.writeQueue[0] = data;
            this.sendData(peripheralID, data)
          }, 500);
        } else {
          this.writeQueue.shift();
          setTimeout(() => {
            if (this.writeQueue.length > 0)
              this.sendData(peripheralID, this.writeQueue[0]);
          }, 500);
        }
      }).catch((error) => {
        console.log("error writing data ", error);
      });
    }
  }
}
const bleModule = new bleHandler();
export default bleModule;

Logs

11:13:28 log Adding data to Queue " Some Important Message text "
11:13:28 log New Queue Length = 1
11:13:28 log ============" Some Important Message text " and length = 28 at Date = 1597680808275
11:13:28 log Writing Message : 9876543211223A2243222C202233223A7B2241636B223A223230302212345
11:13:28 log ============" Some Important Message text " and length = 28 at Date = 1597680808276
11:13:28 log Writing Message : 9876543211223A2243222C202233223A7B2241636B223A223230302212345
11:13:28 log success writing data 
11:13:28 log success writing data 

Now if you check the logs in IOS, i have seen that send data is called twice within (1597680808276 - 1597680808275) 1 ms intervel and it was called from setTimeout function. Is there an issue with setTimeout in js ? or may be react-native issue or safari issue ? and how could i fix this issue. I a have seen a similar issue with been fixed in nodejs few years ago.

Note: Im using react-native-ble-manager for sending / receiving data.

gyan deep
  • 1,880
  • 1
  • 13
  • 9
  • 1
    *"Is there an issue with setTimeout in js ?"* No, of course not, [select is not broken](https://pragprog.com/the-pragmatic-programmer/extracts/tips). :-) The most likely explanation is that `writeData` (or just `sendData`) is getting called twice, scheduling two timer callbacks. I think we'll need more context for the code in order to help you. Please update your question with a runnable [mcve] demonstrating the problem using Stack Snippets (the `[<>]` toolbar button). Stack Snippets support React, including JSX; [here's how to do one](http://meta.stackoverflow.com/questions/338537/). – T.J. Crowder Aug 20 '20 at 10:06
  • It's **really** easy to have two render calls happen in quick succession, so a lot depends on what triggers your `writeData` function (and/or `sendData`, if it's called anywhere other than `writeData`). – T.J. Crowder Aug 20 '20 at 10:07
  • this code is in singleton class which is not a react component, i dnt think react rendering effects this class. And sendData is only called in writeData and in itself recursively. from logs i see that its was not called recursively as delay is just 1ms – gyan deep Aug 20 '20 at 10:11
  • That's all useful context, thanks. We still need a [mcve], ideally a runnable one. (Or a lot more context, but that's kind of nickle-and-diming, and doing an MRE is useful in and of itself, see the link for details.) The overwhelmingly likely thing is that `writeData` is being called twice in rapid succession. – T.J. Crowder Aug 20 '20 at 10:14
  • Updated code and updated logs from oldest log or top to newest at the bottom. – gyan deep Aug 20 '20 at 10:56
  • It sounds like `BleManagerDidUpdateValueForCharacteristic` is firing more than once. Only debugging is gong to find the problem. Good luck. – T.J. Crowder Aug 20 '20 at 11:01
  • I dont think so, as I see log message "Adding data to Queue " Some Important Message text "" being printed only once. thanks – gyan deep Aug 20 '20 at 11:03
  • i would recommend that you don't stumble around in the dark with a `console.log` torch. *Turn on the lights* by using the debugger built into your IDE and browser. **Something** is calling `sendData` twice when you think it's only being called once. You'll just have to debug it to know what is doing that. For instance, at the beginning of `sendData`: `const now = Date.now(); if (this.lastSend && (now - this.lastSend) < 100)) { debugger; } this.lastSend = now;` That'll trigger a breakpoint if `sendData` is called twice within100ms. Good luck! I hope you find it. – T.J. Crowder Aug 20 '20 at 11:12
  • thanks @T.J.Crowder i will try out your method. I guess its very unlikely to see this happen again, the logs i have posted are from production and this was observered only one in almost an year. Nodejs https://github.com/nodejs/node/issues/1191 this issue made me curious. and is there anything wrong with console.logs ? – gyan deep Aug 20 '20 at 11:37

1 Answers1

2

The root cause of the issue is due to the function sendData calling itself.

sendData = (peripheralID, data) => {
  if (data.length > 0 && peripheralID && this.writeQueue.length > 0) {
    // ... 
    if (data.length > 0) {
      setTimeout(() => {
      // ...
      this.sendData(peripheralID, data)                      ---> Recursive call
      }, 500);
    } else {
      // ...
      setTimeout(() => {
        if (this.writeQueue.length > 0)
          this.sendData(peripheralID, this.writeQueue[0]);   ---> Recursive call
        }, 500);
      }
    // ...
  }

The issue of multiple calls to sendData may be resolved by removing the recursion

Here's an example where two timer callbacks, both scheduled to occur 500ms later, arrive in rapid succession:

function example(a) {
    console.log("example:", a, "at", Date.now());
    if (a <= 3) {
        setTimeout(() => {
            example(a * 2);
        }, 500);
    }
}
// Schedule the calls
example(2);
example(3);

// Keep the thread busy
const end = Date.now() + 600;
while (Date.now() < end) {
}

Note how

example: 4 at 1597923771329
example: 6 at 1597923771330

are right next to each other in terms of time.

T.J. Crowder
  • 1,031,962
  • 187
  • 1,923
  • 1,875
Gopinath
  • 4,066
  • 1
  • 14
  • 16
  • I need recursion for sending data every 1/2 sec and I dnt think issue is with recursion as sendData triggered with 1ms delay, not 500ms. – gyan deep Aug 20 '20 at 11:23
  • 1
    @gyandeep - If the thread the JavaScript (and other things) is running on is busy enough, though, the first timer callback could be delayed, so two arrive in rapid succession. I've added an example of that to the answer. – T.J. Crowder Aug 20 '20 at 11:44