search

cloudant / nodejs-cloudant

Cloudant Node.js client library
Apache License 2.0
255 stars 90 forks source link

Issue with db.follow api for cloudant notifications #135

Closed Nagarjuna-S closed 7 years ago

Nagarjuna-S commented 8 years ago

We are using cloudant node module in our application for interactions with cloudant.

We are using following api(logic) for cloudant notifications.

var feed = db.follow({include_docs: true, since: "now"}); feed.filter = function (doc, req) { if (doc._deleted || doc.xxx === "data") return true; return false; }; feed.on('change', function (change) { //Code }); feed.follow();

Our application is receiving events whenever a change happened in cloudant. But intermittently app is crashing with following exception

events.js:141 throw er; // Unhandled 'error' event ^ Error: Database deleted after change: 20-g1AAAAN2eJyd0k0OATEUwPH6iK9LsLQxaZkZdtyE9_raIKMSxpqbcBNuwk1GRyXMQjK16SRN5v_ra5owxlrLGrE-odzu1IwwDnAzIEgG-xQMw Y6GgUy2BwKTBkalif2jCgy7WZatlzVobOxGk0YYTqTw6BRRUQLFnl1x-nbZywXiOIGQWPtgSOmVUVQMh2XCszw8L4QjLeNY8N_hUide5OHjO9xxN4VCSxF7pPwHMnW7spP9WPqc25WXzUFJwqFHzn9 mZ1-cff3YGsc85P_PHZW2b86-53bV2SS5jMAj9-_cD2d_PSTSIxQ0_n5I6yfjKR6t at Feed.on_couch_data (C:\Data\GIT\app\node_modules\cloudant\node_modules\nano\node_modules\follow\lib\feed.js:440:18) at Changes.handle_confirmed_req_event (C:\Data\GIT\app\node_modules\cloudant\node_modules\nano\node_modules\follow\lib\fee d.js:325:30) at emitOne (events.js:77:13) at Changes.emit (events.js:169:7) at Changes.emit_changes (C:\Data\GIT\app\node_modules\cloudant\node_modules\nano\node_modules\follow\lib\stream.js:223:12) at Changes.write_continuous (C:\Data\GIT\app\node_modules\cloudant\node_modules\nano\node_modules\follow\lib\stream.js:176 :8) at Changes.write (C:\Data\GIT\app\node_modules\cloudant\node_modules\nano\node_modules\follow\lib\stream.js:124:17) at Request.ondata (stream.js:31:26) at emitOne (events.js:77:13) at Request.emit (events.js:169:7)

Can you please have a look on this issue and provide us your inputs

glynnbird commented 8 years ago

@jhs ^?

jhs commented 8 years ago

Hi, @Nagarjuna-S. I think I have seen this before. Follow thinks the database is "deleted" because of an unexpected return code.

Are you able to upgrade to a newer version of the software? At the very least, I can add enough error messages so that we can see why it is crashing. (Basically I need to log the HTTP response from the server.)

Thanks.

ajpaton commented 7 years ago

Hi there, I think I've just seen another instance of this problem, with similar (identical) application code and we are using the cloudant module version 1.7.0. We got the stack trace:

Error: Database deleted after change: 35173-g1AAAAOLeJy10b0KwjAQAOCggo76BIq7JSHBmEkXJx-i9pIUK_0B0clBX0R08yUEfRN9D4cam2pXhXa5g-O4j7sLEUKtRV2hvgKZrPREAXECiAZBABgTR4bJRnnx2on1OjS9NQ9BN03T5aIOCHXOkak1lQBFBftpyD8W9EyE8ZdrPy2niMbaL5-bvDm34A6W04wRTsrn5m9uVxxzmnGYepIKXjoXN0xEe5OMeMw3vGSkx4BKKisiT5a85lu69qgchjCiFZE3S95zcpuRI6BcC1wR-bDk55ezjCTgEwXw06zlC1-FGL4
 at Feed.on_couch_data (/home/vcap/app/node_modules/follow/lib/feed.js:440:18)
 at Changes.handle_confirmed_req_event (/home/vcap/app/node_modules/follow/lib/feed.js:325:30)
 at emitOne (events.js:77:13) at Changes.emit (events.js:169:7)
 at Changes.emit_changes (/home/vcap/app/node_modules/follow/lib/stream.js:223:12)
 at Changes.write_continuous (/home/vcap/app/node_modules/follow/lib/stream.js:176:8)
 at Changes.write (/home/vcap/app/node_modules/follow/lib/stream.js:124:17)
 at Request.ondata (stream.js:31:26) at emitOne (events.js:77:13)
 at Request.emit (events.js:169:7) at IncomingMessage.<anonymous> (/home/vcap/app/node_modules/follow/node_modules/request/request.js:1164:12)
 at emitOne (events.js:77:13) at IncomingMessage.emit (events.js:169:7)
 at readableAddChunk (_stream_readable.js:153:18)
 at IncomingMessage.Readable.push (_stream_readable.js:111:10)
 at HTTPParser.parserOnBody (_http_common.js:124:22)
 at TLSSocket.socketOnData (_http_client.js:320:20)
 at emitOne (events.js:77:13) at TLSSocket.emit (events.js:169:7)
 at readableAddChunk (_stream_readable.js:153:18)
 at TLSSocket.Readable.push (_stream_readable.js:111:10)
 at TLSWrap.onread (net.js:536:20)

which is nearly, but not quite, identical to the one reported back in June 2016.

Do you have any more thoughts on why this might be happening? Is anything new in v1.7.0 which might make this more likely? Does any of the extended diagnostics on http comms you mentioned earlier help with this (and how would we access that)?

We saw this 4 times in quick succession during the morning of 24th January, after restaging our app on 19th January (which picked up cloudant v1.7.0) but we did have one occurrence of it on 7 December as well.

Would appreciate any guidance that the maintainers can offer on this, as I'm not clear if there is anything we can do to avoid future occurrences of this in our production system.

smithsz commented 7 years ago

It's likely the server was undergoing maintenance at the time. Cloudant terminates the changes feed, sending a last_seq, if the node serving your request is placed in maintenance mode (see https://github.com/apache/couchdb-fabric/blob/master/src/fabric_view_changes.erl#L94). The expectation here is that the client will retry the request using the last_seq provided in the response.

Feed is just throwing an error here under the false assumption that the database has been deleted (see https://github.com/iriscouch/follow/blob/master/lib/feed.js#L438). I think the solution is to always retry the /_changes request if it's terminated by the server. If the following retry attempt returns a 404 then we can legitimately say the database has been deleted.

glynnbird commented 7 years ago

@jhs ^ this seems to be a rare but inconvenient bug in the follow library

smithsz commented 7 years ago

This fixed is now available in nodejs-cloudant, version 1.8.0.