Task in queue expires immediately

[donbarthel]

I'm somewhat sure that this isn't a issue with firebase-queue but with my production environment. I'm documenting it here in case it helps others figure out why firebase-queue isn't working for them.

In queue_worker.js is this line:

var expires = Math.max(0, startTime - now + self.taskTimeout);

Since 'now' is later that 'startTime' the expression 'startTime - now' should be a small negative. But on my production server its a very large positive. And all sorts of hell breaks loose because of it.

When we put firebase-queue into production this wasn't an issue. But something has changed and I'll be looking into what that might be.

I solved the issue with this hack, changing the code to:

var expires = self.taskTimeout;

[cbraynor]

Sorry for the slow reply, I have a few questions:

• Is the system time set correctly in your production environment?
• Are the versions of Node you're using the same in dev and prod?
• What OS / version of Node.js are you using in production?
• What does 'a very large positive' mean in this case - close to Number.MAX_SAFE_INTEGER, or just a few thousand?
• Does now look like the current time since epoch in millis, or is startTime the number that's wrong?
• Could either value be in seconds instead of milliseconds somehow?

[donbarthel]

Is the system time set correctly in your production environment?

Yes, just now: Sun Feb 14 23:31:48 UTC 2016

Are the versions of Node you're using the same in dev and prod?

No. Dev: v4.3.0, prod: v4.2.2.

What OS / version of Node.js are you using in production?

OS: CentOS Linux release 7.2.1511 (Core)
Node: v4.2.2

What does 'a very large positive' mean in this case - close to Number.MAX_SAFE_INTEGER, or just a few thousand?

Near the max safe integer, really large.

Does now look like the current time since epoch in millis, or is startTime the number that's wrong?

I don't think either is wrong. I recall that startTime was slightly less than now so that (startTime - now) should yield a small negative. But its like its using unsigned math on my system to yield a large positive (i.e. reminds me of unsigned two's complement math).

Could either value be in seconds instead of milliseconds somehow?

I recall that it they were properly milliseconds since the epoch.

[donbarthel]

FYI, my code change also seems to be a fix/hack for issue #48, symptoms which I started having with a new project that I didn't until now apply this change to.

[donbarthel]

Just FYI, I updated from Firebase Queue v1.4 to v1.6 and this issue is still a problem for me. Not in development on my laptop (Node v6.4.0) but in production on the server (I use Webfaction as my host with Node v6.2.0).

And my fix (documented above) applied to Firebase Queue v1.6 still works.

[cbraynor]

Hey @donbarthel - can you try 1.6.1 for me (released yesterday) - there was a fix regarding timed out tasks that might be relevant

[donbarthel]

OK I tried it, not thoroughly, on the server that was having issues. And it does seem to work. Please leave this issue open for a few weeks so I can report on more thorough testing after the holidays.

Thanks for keeping on top of this, Firebase Queue is extremely important for our application. Essentially, our app is using Firebase Security Rules to give mostly read-only access to client apps, and only to selected parts of the database. If a client wants to make a change it posts a request through a queue and a server side process, not exposed to the world, picks up the request, validates it, then implements it.

[donbarthel]

OK I think my issue was not fixed by Firebase Queue 1.6.1.

Today, my Node app using Firebase Queue stopped taking things off the queue. Restarting the Node app didn't help. Then I reimplemented my hack (above) which caused the Node app to start working again. Then I took out my hack and then the Node app would fire exactly 18 times for each item placed on the queue. Wierd.

So I've reimplemented my hack in 1.6.1.

:(