Replication completely resets on timeout

[remy]

Replicating skimdb, last_seq is: 11803 (6.92%)
Replicating skimdb, last_seq is: 12003 (7.04%)
Replicating skimdb, last_seq is: 12203 (7.16%)
Replicating skimdb, last_seq is: 12403 (7.27%)
Replicating skimdb, last_seq is: 12603 (7.39%)
Replicating skimdb, last_seq is: 12803 (7.51%)
Replicating skimdb, last_seq is: 13003 (7.63%)
Replicating skimdb, last_seq is: 13203 (7.74%)
error during replication with skimdb
{"status":503,"name":"pound_service_unavailable","message":"Database encountered an unknown error"}
Replicating skimdb, last_seq is: 1 (0%)
Replicating skimdb, last_seq is: 2 (0%)
Replicating skimdb, last_seq is: 200 (0.11%)
Replicating skimdb, last_seq is: 401 (0.23%)
Replicating skimdb, last_seq is: 601 (0.35%)
error during replication with skimdb
{"status":503,"name":"pound_service_unavailable","message":"Database encountered an unknown error"}
Replicating skimdb, last_seq is: 1 (0%)
Replicating skimdb, last_seq is: 2 (0%)
Replicating skimdb, last_seq is: 200 (0.11%)
Replicating skimdb, last_seq is: 401 (0.23%)
Replicating skimdb, last_seq is: 601 (0.35%)
Replicating skimdb, last_seq is: 801 (0.47%)
error during replication with skimdb
{"status":503,"name":"pound_service_unavailable","message":"Database encountered an unknown error"}
(node) warning: possible EventEmitter memory leak detected. 11 listeners added. Use emitter.setMaxListeners() to increase limit.
Trace
    at PouchDB.addListener (events.js:160:15)
    at PouchDB.once (events.js:185:8)
    at new Changes (/Users/remy/.nvm/v0.10.38/lib/node_modules/local-npm/node_modules/pouchdb/lib/changes.js:41:6)
    at PouchDB.AbstractPouchDB.changes (/Users/remy/.nvm/v0.10.38/lib/node_modules/local-npm/node_modules/pouchdb/lib/adapter.js:680:10)
    at getChanges (/Users/remy/.nvm/v0.10.38/lib/node_modules/local-npm/node_modules/pouchdb/lib/replicate/replicate.js:332:23)
    at /Users/remy/.nvm/v0.10.38/lib/node_modules/local-npm/node_modules/pouchdb/lib/replicate/replicate.js:376:9

It seems to have reset after around 7%...

[remy]

Doesn't seem to be linked to the event listeners, but the 503 causes the replication to reset. I'm not sure if that's normal or not...

More logs:

Navigate to http://localhost:16984/_utils for the Fauxton UI.

Replicating skimdb, last_seq is: 1 (0%)
Replicating skimdb, last_seq is: 2 (0%)
Replicating skimdb, last_seq is: 200 (0.11%)
Replicating skimdb, last_seq is: 401 (0.23%)
Replicating skimdb, last_seq is: 601 (0.35%)
Replicating skimdb, last_seq is: 801 (0.47%)
Replicating skimdb, last_seq is: 1001 (0.58%)
Replicating skimdb, last_seq is: 1201 (0.7%)
Replicating skimdb, last_seq is: 1401 (0.82%)
Replicating skimdb, last_seq is: 1601 (0.93%)
Replicating skimdb, last_seq is: 1801 (1.05%)
Replicating skimdb, last_seq is: 2001 (1.17%)
Replicating skimdb, last_seq is: 2201 (1.29%)
Replicating skimdb, last_seq is: 2401 (1.4%)
Replicating skimdb, last_seq is: 2601 (1.52%)
Replicating skimdb, last_seq is: 2801 (1.64%)
error during replication with skimdb
{"status":503,"name":"pound_service_unavailable","message":"Database encountered an unknown error"}
Replicating skimdb, last_seq is: 1 (0%)
Replicating skimdb, last_seq is: 2 (0%)
Replicating skimdb, last_seq is: 200 (0.11%)
Replicating skimdb, last_seq is: 401 (0.23%)
Replicating skimdb, last_seq is: 601 (0.35%)
Replicating skimdb, last_seq is: 801 (0.47%)
Replicating skimdb, last_seq is: 1001 (0.58%)
Replicating skimdb, last_seq is: 1201 (0.7%)
error during replication with skimdb
{"status":503,"name":"pound_service_unavailable","message":"Database encountered an unknown error"}
Replicating skimdb, last_seq is: 1 (0%)
Replicating skimdb, last_seq is: 2 (0%)
Replicating skimdb, last_seq is: 200 (0.11%)
Replicating skimdb, last_seq is: 401 (0.23%)
Replicating skimdb, last_seq is: 601 (0.35%)

[nolanlawson]

I think the reason the replication is resetting is because the target database is read-only. We have a longstanding issue where we need to write _local checkpoints to the remote database in order to keep track of our progress in replicating from that database.

As for the EventEmitter warning, that's definitely a bug that I thought we had fixed awhile ago. Filed: pouchdb/pouchdb#4093

[daleharvey]

If the database is read only then we should fallback to just relying on the local checkpoint (https://github.com/pouchdb/pouchdb/blob/master/lib/replicate/checkpointer.js#L101) as long as the error we get back is as expected, is that changing somehow?

[remy]

There's definitely something super wrong.

I left local-npm running and it go to 100%, then when restarting and catching up with changes it randomly drops back down to zero:

...
Error: ETIMEDOUT
error during replication with skimdb
Error: ETIMEDOUT
error doing logger.info() on https://skimdb.npmjs.com/registry
Error: ETIMEDOUT
Replicating skimdb, last_seq is: 175769 (98.82%)
Replicating skimdb, last_seq is: 175771 (98.83%)
error during replication with skimdb
Error: ETIMEDOUT
error doing logger.info() on https://skimdb.npmjs.com/registry
Error: ETIMEDOUT
Replicating skimdb, last_seq is: 1 (0%)
Replicating skimdb, last_seq is: 2 (0%)
Replicating skimdb, last_seq is: 200 (0.11%)
Replicating skimdb, last_seq is: 401 (0.22%)
Replicating skimdb, last_seq is: 402 (0.22%)
Replicating skimdb, last_seq is: 403 (0.22%)
Replicating skimdb, last_seq is: 601 (0.33%)
Replicating skimdb, last_seq is: 602 (0.33%)
Replicating skimdb, last_seq is: 603 (0.33%)
...

[nolanlawson]

Based on the output it seems like you are not using the latest version. Could you update to 1.4.2 and try again?

[nolanlawson]

Oh shoot my bad, excuse me. I opened a PR and then never merged it. I'll publish 1.4.3 right now.

[nolanlawson]

Should be fixed by #41, please reopen if it's not.

[remy]

Sorted.

I've seen all of the view docs in pouch, is it possible to query this local-npm using those desig docs? i.e. find all the modules that depend on semver for instance?

[nolanlawson]

Yeah, that's actually a really neat idea. In the Fauxton UI (http://localhost:16984/_utils) I can see a ton of secondary indexes that are already in that _design/app ddoc, but since it's a replicated CouchDB, you can also add whatever design docs you want, and then query them.

As a test, I did this:

curl http://localhost:16984/skimdb/_design/by_maintainer -X PUT -H 'Content-Type: application/json' --data-binary '{"_id":"_design/by_maintainer","views":{"by_maintainer":{"map":"function (doc) {\n  if (doc.maintainers) {\n    for (var i = 0; i < doc.maintainers.length; i++) {\n      var email = doc.maintainers[i].email;\n      if (email) {\n        emit(email);  \n      }\n    }\n  }\n}"}},"language":"javascript"}'
curl 'http://localhost:16984/skimdb/_design/by_maintainer/_view/by_maintainer?key=%22nolan@nolanlawson.com%22&limit=5'

The secondary index is slow to build, but it works! Prints out:

{"total_rows":203396,"offset":0,"rows":[{"key":"nolan@nolanlawson.com","id":"add-cors-to-couchdb","value":null},{"key":"nolan@nolanlawson.com","id":"blob-util","value":null},{"key":"nolan@nolanlawson.com","id":"chord-magic","value":null},{"key":"nolan@nolanlawson.com","id":"couchdb-harness","value":null},{"key":"nolan@nolanlawson.com","id":"debug-websql","value":null}]}

For querying modules that depend on semver, I guess you would need to emit all dependency versions or maybe just emit if any version numbers start with a ^ or a ~. The Fauxton UI is actually pretty nice for editing these kinds of ddocs; highly recommended.