Skip to content
This repository has been archived by the owner on Dec 20, 2019. It is now read-only.

SDK doesn't response after sending too much commands in a row / after losing connection for a moment. #37

Open
omeryagmurlu opened this issue Dec 26, 2015 · 26 comments

Comments

@omeryagmurlu
Copy link

With my Ollie, I am able connect and send/get data to/from Ollie but I have a problem. After noble loses connection with Ollie for a moment, commandQueue property of Sphero constructor fills up quickly and it gets stuck and new commands don't execute on time, (they execute after 1 or 2 min). And the queue is processed when a new command is sent (line 177), so it becomes a vicious circle with no end. One solution I found was to reduce the 256 limit to 1, but it defeats the purpose of the queue.

@deadprogram
Copy link
Contributor

Hi, @omeryagmurlu thanks for the info. Sounds like we could accommodate this by attempting a reconnection in that case. Right now we just throw bad response packets away, but do not attempt to clean up the command queue. Perhaps we should throw away all outstanding requests in that case? What behaviour would you expect or like it to have?

@omeryagmurlu
Copy link
Author

It should attempt a reconnection, clear the queue, and emit an event (reconnection). But attempting to reconnect only when a bad response comes doesn't fix this problem, if noble doesn't even get a bad response, then the queue will fill again.

@omeryagmurlu
Copy link
Author

I found out that the queue simply gets stuck, I thought that it was at least parsing the zero index each time a new command is sent, but apparently, it doesn't.

Here is a simple script

var orb = (require("../"))(process.env.PORT);

orb.connect(function() {
  setInterval(function() {
    console.log("Queue is:", orb.commandQueue);
    orb.randomColor();
  }, 500);
});

the changes I made to the source code are:
I changed this line with:

  var timeoutId = setTimeout( function() {
    console.log("disconnected")
    cb.bind(this)
  }.bind(this), this.timeout);

Here is the output:

omer@xxxx:~/Desktop/sphero.js/examples$ PORT="ef66143e996d" node asdfg.js
Queue is: []
Queue is: []
Queue is: []
Queue is: []
Queue is: []
Queue is: []
Queue is: []
Queue is: []
Queue is: []
Queue is: []
Queue is: []
disconnected
Queue is: []
Queue is: [ { packet: [ 255, 255, 2, 32, 11, 5, 183, 9, 44, 1, 224 ],
    cb: undefined } ]
Queue is: [ { packet: [ 255, 255, 2, 32, 11, 5, 183, 9, 44, 1, 224 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 12, 5, 9, 99, 110, 1, 241 ],
    cb: undefined } ]
Queue is: [ { packet: [ 255, 255, 2, 32, 11, 5, 183, 9, 44, 1, 224 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 12, 5, 9, 99, 110, 1, 241 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 13, 5, 152, 161, 84, 1, 61 ],
    cb: undefined } ]
Queue is: [ { packet: [ 255, 255, 2, 32, 11, 5, 183, 9, 44, 1, 224 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 12, 5, 9, 99, 110, 1, 241 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 13, 5, 152, 161, 84, 1, 61 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 14, 5, 40, 97, 143, 1, 177 ],
    cb: undefined } ]
Queue is: [ { packet: [ 255, 255, 2, 32, 11, 5, 183, 9, 44, 1, 224 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 12, 5, 9, 99, 110, 1, 241 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 13, 5, 152, 161, 84, 1, 61 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 14, 5, 40, 97, 143, 1, 177 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 15, 5, 41, 167, 40, 1, 208 ],
    cb: undefined } ]
Queue is: [ { packet: [ 255, 255, 2, 32, 11, 5, 183, 9, 44, 1, 224 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 12, 5, 9, 99, 110, 1, 241 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 13, 5, 152, 161, 84, 1, 61 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 14, 5, 40, 97, 143, 1, 177 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 15, 5, 41, 167, 40, 1, 208 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 16, 5, 187, 226, 118, 1, 180 ],
    cb: undefined } ]
Queue is: [ { packet: [ 255, 255, 2, 32, 11, 5, 183, 9, 44, 1, 224 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 12, 5, 9, 99, 110, 1, 241 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 13, 5, 152, 161, 84, 1, 61 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 14, 5, 40, 97, 143, 1, 177 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 15, 5, 41, 167, 40, 1, 208 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 16, 5, 187, 226, 118, 1, 180 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 17, 5, 111, 200, 133, 1, 10 ],
    cb: undefined } ]
Queue is: [ { packet: [ 255, 255, 2, 32, 11, 5, 183, 9, 44, 1, 224 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 12, 5, 9, 99, 110, 1, 241 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 13, 5, 152, 161, 84, 1, 61 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 14, 5, 40, 97, 143, 1, 177 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 15, 5, 41, 167, 40, 1, 208 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 16, 5, 187, 226, 118, 1, 180 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 17, 5, 111, 200, 133, 1, 10 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 18, 5, 247, 34, 86, 1, 86 ],
    cb: undefined } ]
Queue is: [ { packet: [ 255, 255, 2, 32, 11, 5, 183, 9, 44, 1, 224 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 12, 5, 9, 99, 110, 1, 241 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 13, 5, 152, 161, 84, 1, 61 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 14, 5, 40, 97, 143, 1, 177 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 15, 5, 41, 167, 40, 1, 208 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 16, 5, 187, 226, 118, 1, 180 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 17, 5, 111, 200, 133, 1, 10 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 18, 5, 247, 34, 86, 1, 86 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 19, 5, 170, 127, 111, 1, 44 ],
    cb: undefined } ]
Queue is: [ { packet: [ 255, 255, 2, 32, 11, 5, 183, 9, 44, 1, 224 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 12, 5, 9, 99, 110, 1, 241 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 13, 5, 152, 161, 84, 1, 61 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 14, 5, 40, 97, 143, 1, 177 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 15, 5, 41, 167, 40, 1, 208 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 16, 5, 187, 226, 118, 1, 180 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 17, 5, 111, 200, 133, 1, 10 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 18, 5, 247, 34, 86, 1, 86 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 19, 5, 170, 127, 111, 1, 44 ],
    cb: undefined },
  { packet: [ 255, 255, 2, 32, 20, 5, 41, 223, 202, 1, 241 ],
    cb: undefined } ]

It goes on but I cut it.

Also, the strange thing is, my Ollie is next to my Computer while I run this script. So it can't be "disconnected".

@dimorphic
Copy link

I was just debugging the same Sphero.prototype._queueCallback function looking for Command sync response was lost.

I'm experiencing the same issue here, as my BB8 is dying / becoming unresponsive or not reconnecting at all (just after a few attempts / seconds), after a bad 'command' que. Same as @omeryagmurlu , my BB8 is next to me.

@deadprogram
Copy link
Contributor

Thanks for all the detailed info. Also, which OS & node versions are you using, @omeryagmurlu & @dimorphic ?

@dimorphic
Copy link

@deadprogram Running OSX 10.11.2, and i've tried both Node 4.1.2 and 0.12.0. Atm on 0.12.0.

@omeryagmurlu
Copy link
Author

@deadprogram Running Ubuntu 15.04 and node versions are 4.2.4 and 4.1.2

@olcar
Copy link

olcar commented Jan 16, 2016

Running on OS X 10.11.2 (15C50) with Node v5.2.0 here and I'm not able to reproduce the issue.

Even by setting a really low timeout (1) in your simple script @omeryagmurlu, the queue quickly fills up but my BB8 device doesn't disconnect. Do you need to run it for a long time?

@deadprogram
Copy link
Contributor

There were some improvements in the 0.8.0 release, just wondering @omeryagmurlu & @dimorphic could either or both of you please try again with the latest code? Thanks.

@debu66er
Copy link

debu66er commented May 21, 2016

@dimorphic I am experiencing the same issue. Working with the BB8 suddenly I get:

Unhandled rejection Error: Command sync response was lost.
at Sphero.handler (/Users/sp11382/IoT2BB8/node_modules/sphero/lib/sphero.js:252:21)
at Timer.listOnTimeout (timers.js:92:15)

for any command I send. And I haven't found the pattern to get it working again. Did you find a way to fix it? I tried hard reset on the platform but it still failing. It seems a matter of time but I would like to understand when this happens and how to recover.

I am using: v0.9.2 on Mac OS v10.11.5 with Node v4.4.4

@dimorphic
Copy link

Wow, first of all, sorry for missing in action! -.-

@debu66er : Looking back at my code (4 months old now, so it might not be up-2-date with latest release), what I ended doing was add a throttle delay to all the movement commands, in order to prevent disconnect (100 ms was ok). Still the droid would disconnect sometimes, as i didn't throttle delay every command, or just because it's moody or w/e.

Also, for my examples, I made a process respawner helper, which helped me in reconnecting to my droid and other devices when / if needed. :)

I can't really recall if i've made some custom tweaks to my local installed sphero.js lib, which i didn't manage to get back here, gonna check as soon as i get some time.

You can check the code at : https://github.com/dimorphic/bb8

Movement throttle helpers (nothing fancy) src/lib/bb8/commands/movement.js#L92

@deadprogram : As soon as i have some free time, gonna try with the latest release and see if there's still an issue. That if this issue wasn't resolved yet and not closed, as I see the release version is 0.9.2 currently. Also, why no changelogs on releases? :(

@debu66er
Copy link

Hi @dimorphic, thanks for your quick answer.
My understanding is that throttle delay objective is to avoid sending too much commands at the same time, right?
In my case, I am getting the error just with a simple single command like bb8.color("red");
Just with such simple code I get:

Unhandled rejection Error: Command sync response was lost.
at Sphero.handler (/Users/sp11382/IoT2BB8/node_modules/sphero/lib/sphero.js:252:21)
at Timer.listOnTimeout (timers.js:92:15)

How I get to this situation? I haven't a clear idea. It is after a while, 10-15 minutes but not sending huge amount of commands. Then it doesn't matter what I do, just a single and isolated command will fail.
It seems to me it is not your same case, right?

@omeryagmurlu
Copy link
Author

@debu66er Sphero sleeps after (by default) 6 mins of inactivity. Are you sure that your bb8 is awake while you're sending commands?

Here is the program I was working on. I hadn't time to check if it still works, but if there hasn't been huge changes to the API, it should work. You can look at the code to see whether youre doing something wrong.

Before this repo supported BB8 (bzw. Ollie) I had made a repo to control them. It don't develop it anymore but you can give it a shot. It was working fine last time I checked.

https://github.com/omeryagmurlu/olliejs

@dimorphic
Copy link

dimorphic commented May 21, 2016

@debu66er : Indeed, the throttling is just so you don't spam it, killing it. In my examples, i use either an Xbox controller or Myo armband, from which i get a data stream to use for direction / speed on BB8.

As i said, i also had some random disconnects back then. Sometimes, suddenly, even after playing for minutes, it would die / disconnect, eventho it was just sitting (no movement commands) and i was just changing colors (one at a time). Can't recall the stack trace error if any. Also, i was running v0.5.0 back then, so my feedback here might be off. :)

@debu66er
Copy link

debu66er commented May 21, 2016

Thanks @omeryagmurlu I will check your SDK and give it a try.
In my case BB8 is awake. In fact I connect it with the official android app. Then I dicon and connect my app that only set a color and I get that error.
But as I said, I know the code is fine because it works fine for 10-15 minutes. If I leave BB8 rest (don't know if battery goes away or what) but tomorrow for example, I try my app and it works.

So what I am not able to understand is why the official app plays with BB8 (so it is answering to commands) and fater that, I connect mine (it connects correctly), I send just a command and I get the error saying BB8 never answered :-/

Unhandled rejection Error: Command sync response was lost.
at Sphero.handler (/Users/sp11382/IoT2BB8/node_modules/sphero/lib/sphero.js:252:21)
at Timer.listOnTimeout (timers.js:92:15)

Checking the source code of that line looks like:

Sphero.prototype._queuePromise = function(cmdPacket, resolve, reject) {
  var seq = cmdPacket[4];

  var handler = function(err, packet) {
    clearTimeout(this.responseQueue[seq].timeoutId);
    this.responseQueue[seq] = null;
    this.busy = false;

    if (typeof resolve === "function") {
      if (!err && !!packet) {
        resolve(packet);
      } else {
        var error = new Error("Command sync response was lost.");
        reject(error);
      }
    }

    this._execCommand();
  };

Am I correct thinking that BB8 receives my command but never answers?

@debu66er
Copy link

I forgot to paste my simplified test case:

// BB8 Library
var sphero = require("sphero");
// BB8 Library initialization and connection
var bb8 = sphero("818d9b93a854439f956e1e811be16a00"); // Change BLE address accordingly 
console.log("##### BB8 info: " + JSON.stringify(bb8)); 
bb8.connect(function() 
{
    console.log("##### Connected to BB8");   
        bb8.color("red");
});

I think it is really simple and correct, isn't it?
What can be happening to BB8? I try hard reset pressing the button on the platform, play with the mobile so everything is cleaned....
Can it be an issue with Bluetooth in Mac that after some time it fails some how?

@debu66er
Copy link

Thanks @dimorphic, so for those specific cases you comment that suddenly it stops working... how did you get the bb8 back? Any tip or trick? Just wait for couple of hours?

@dimorphic
Copy link

I just restart the whole reconnect process. The droid is not stuck, but only suddenly disconnects and dies, and i'm forced to reconnect.

@debu66er
Copy link

Ok @dimorphic, that is not my case. In my case I can connect but any command I send fails with previous exception. Also all examples from the SDK, so it is not my code.
I tried to reset Mac Bluetooth device but doesn't help neither.
Now I am checking what is the amount of time I need to get it working again... it is very estrange.

@debu66er
Copy link

At the end, I am not able to explain when this issue happens. It seems some how random and related with battery. But I was able to find a not scientific procedure to recover it which is connect() and disconnect() several times from my app previous reset once on the platform.

What I see is that when connecting, BB8 executes the commands that failed before. It is like it has memory and as it didn't answered before it is trying to answer now. So after I connect and disconnect several times it seems I clean its queue or whatever it has and it starts working again.

Any function to clean, reset or whatever it needs to start from scratch?

@debu66er
Copy link

Finally, a ping() call after connect() function avoided any more hanged.
BTW, as the subject of the issue says: SDK doesn't response after sending too much commands, when listening to collision events and sending a red color for example for each event, which happens a lot and very fast, I got the lost of response exception (but it doesn't hang anymore as I said above):

Unhandled rejection Error: Command sync response was lost.
at Sphero.handler (/Users/sp11382/IoT2BB8/node_modules/sphero/lib/sphero.js:252:21)
at Timer.listOnTimeout (timers.js:92:15)

@ShahNewazKhan
Copy link

ShahNewazKhan commented Feb 22, 2017

hi @debu66er can you please provide a code sample of the ping() call you make after connecting. I am facing the same issue where I am able to connect to the bb8 from OS X, however it is losing the connection after the command is issued and my Nodejs app running in electron is not getting a response back from bb8 and I get the following, even for the ping() command:

Unhandled rejection Error: Command sync response was lost.
    at Sphero.handler (/Users/shah/projects/node/ai8/node_modules/sphero/lib/sphero.js:252:21)
From previous event:
    at Sphero.command (/Users/shah/projects/node/ai8/node_modules/sphero/lib/sphero.js:180:10)
    at Sphero.device.setRgbLed (/Users/shah/projects/node/ai8/node_modules/sphero/lib/devices/sphero.js:369:12)
    at Sphero.device.color (/Users/shah/projects/node/ai8/node_modules/sphero/lib/devices/custom.js:168:19)
    at file:///Users/shah/projects/node/ai8/js/orb.js:7:7�[0m

EDIT

I have also tried to run this from a fresh install on Node inside a pure node project and get the same error:

Error: Command sync response was lost.
    at Sphero.handler (/Users/shah/projects/node/bb8/node_modules/sphero/lib/sphero.js:252:21)
    at ontimeout (timers.js:365:14)
    at tryOnTimeout (timers.js:237:5)
    at Timer.listOnTimeout (timers.js:207:5)
From previous event:
    at Sphero.command (/Users/shah/projects/node/bb8/node_modules/sphero/lib/sphero.js:180:10)
    at Sphero.device.ping (/Users/shah/projects/node/bb8/node_modules/sphero/lib/devices/core.js:21:12)
    at /Users/shah/projects/node/bb8/index.js:8:10
    at runCallback (timers.js:649:20)
    at tryOnImmediate (timers.js:622:5)
    at processImmediate [as _immediateCallback] (timers.js:594:5)

My current environment is:

ProductName:	Mac OS X
ProductVersion:	10.11.6
BuildVersion:	15G31

node -v
v6.9.5

npm -v 
3.10.10

system_profiler SPBluetoothDataType | sed -n "/Apple Bluetooth Software Version\:/,/Manufacturer\:/p" | tr -s "[\n]" "[ ]" | sed "s:.*Address\: ::g" | sed "s: Manufacturer\:.*::g" | grep "[[:graph:]]"

80-E6-50-1B-50-31 Bluetooth Low Energy Supported: Yes Handoff Supported: Yes Instant Hot Spot Supported: Yes

@debu66er
Copy link

debu66er commented Mar 1, 2017 via email

@ShahNewazKhan
Copy link

ShahNewazKhan commented Mar 1, 2017

Hi @debu66er thanks for your input, I believe I am having a slightly different issue as the response does not come back from the BB8 unit once the command being sent is executed. Therefore once I issue the ping() command after connecting, it is executed however the response does not come back.

The issue is in the Sphero.prototype._queuePromise function, I haven't yet, but I will update this thread with what the err and packet objects state are from the handler function that is causing the 'Command sync response was lost.' clause to be executed.

/Sphero_NPM_Module/lib/sphero.js

/**
 * Adds a promise to the queue, to be executed when a response
 * gets back from the sphero.
 *
 * @private
 * @param {Array} cmdPacket the bytes array to be send through the wire
 * @param {Function} resolve function to be triggered on success
 * @param {Function} reject function to be triggered on failure
 * @example
 * sphero._execCommand(packet, resolve, reject);
 * @return {void}
 */
Sphero.prototype._queuePromise = function(cmdPacket, resolve, reject) {
  var seq = cmdPacket[4];

  // ***** I will check the err and packet objects in this function and update *****
  var handler = function(err, packet) {
    clearTimeout(this.responseQueue[seq].timeoutId);
    this.responseQueue[seq] = null;
    this.busy = false;
    
    if (typeof resolve === "function") {
      if (!err && !!packet) {
        resolve(packet);
      } else {
        var error = new Error("Command sync response was lost.");
        reject(error);
      }
    }

    this._execCommand();
  };

  var timeoutId = setTimeout(handler.bind(this), this.timeout);

  this.responseQueue[seq] = {
    handler: handler.bind(this),
    timeoutId: timeoutId,
    did: cmdPacket[2],
    cid: cmdPacket[3]
  };
};

This was referenced Nov 24, 2017
@jasherone
Copy link

Hi there,
I think I have very common issue.

Quick description of the issue
I am trying to use this https://github.com/charliegerard/leap_sphero.git and my Sphero SPRK returns "Command sync response was lost." after few seconds of sending commands to it and the execution of commands starts to lag

My Questions
1/ Did anyone manage to fix this issue?
2/ I guess since I have Sphero SPRK its the same hardware and it should be the same issue right?

Fixes tried
1/ Two different MacOS versions (I didnt try Linux or Windows)
2/ I found that the issue could be caused by noble version 1.8.0. I downgraded noble to 1.7.0, but I still have the issue. As found here [https://github.com//issues/85]
3/ Call ping() after connect() as @debu66er suggested
4/ @olcar said it works for him with Node 5.2.0 so I tried also downgrading to this version

Current Config
Mac OSX 10.12.6
Sphero model: S003, SPRK (not plus)
"express": "^4.16.2",
"leapjs": "^0.6.4",
"noble": "^1.7.0",
"serialport": "^3.1.2",
"sphero": "^0.9.2"

Detailed Description of Issue
I only send roll commands to sphero, and I limit them to one command every 200ms.

Fist few commands execute instantly, but then after 10-20 seconds (about 30-50 commands), they suddenly they start lagging up to few seconds long lags and I was getting the same message as mentioned above.

Unhandled rejection Error: Command sync response was lost.
at Sphero.handler (/Users/martin/Workspace/LEAP Sphero MJ/node_modules/sphero/lib/sphero.js:252:21)

The error line is in _queuePromise function mentioned above

I tried sending commands more often and less often, it made no difference.

And I also tried waiting (for example 60 seconds) and then started sending commands. It looks like Sphero starts to lag 10-20 seconds after I start sending commands no matter how many commands I send and how much I waited before.

@avidj
Copy link

avidj commented Apr 9, 2018

Hi all,
I am having the same problem with the connection (Sync response lost). However, only if I turn on sensor streaming. I tried for gyro and accelerometer. I have now turned off all sensor streaming and set the frequency of roll commands to 200. Now it seems to run stable. A frequency of 100 is also fine, 50 is fragile even without sensors. If I turn on gyro or accelerometer, or probably any other sensor, with roll-commands every 100-200 ms then sphero begins dropping commands. It still reacts but totally out of sync resulting in very false movements. In the original code I had all sensors stream from the start resulting in total loss of connection after 3-4 seconds, no matter how many roll commands I sent. I assume the connection is just overwhelmed by the sensor data stream.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

No branches or pull requests

8 participants