Heartbeat request failures after login

flootr commented 7 years ago

After a successful login I get the following request failure messages printed to the console. The error occurs only if a user is logged in.

Note, there are 2 requests. The first one is successful, but the second isn't.

I tried to run the application in different browsers and it seems this error occurs if hoodie (or pouchdb) uses WebSQL and not IndexedDB (not sure about the determinism).

Hoodie is running on version 28.1.1, pouchdb on 6.2.0

❯ npm ls | grep hoodie
├─┬ hoodie@28.1.1
│ ├─┬ @hoodie/admin@1.3.1
│ ├─┬ @hoodie/client@10.0.2
│ │ ├─┬ @hoodie/account-client@6.0.2
│ │ ├─┬ @hoodie/connection-status@4.0.1
│ │ ├─┬ @hoodie/log@2.1.0
│ │ ├─┬ @hoodie/store-client@8.1.0
│ │ │ ├── hoodie-zuul-config@2.0.0
│ │ │ ├─┬ pouchdb-hoodie-api@2.0.0
│ │ │ └─┬ pouchdb-hoodie-sync@2.1.1
│ ├─┬ @hoodie/server@23.0.0
│ │ ├─┬ @hoodie/account-server@6.1.0
│ │ │ ├─┬ @hoodie/account-server-api@3.8.1
│ │ ├─┬ @hoodie/store-server@3.0.0
│ │ │ ├─┬ @hoodie/store-server-api@2.0.0
│ │ │ │ ├── pouchdb-hoodie-api@2.0.0 deduped

gr2m commented 7 years ago

How do you start Hoodie? Do you set dbUrl? If you do, what CouchDB version do you use?

Can you set loglevel to verbose and show the logs you see in the terminal? E.g. npm start -- --loglevel=verbose

flootr commented 7 years ago

$ hoodie --dbUrl=http://flootr:secret@localhost:5984/ --port=7777

and CouchDB runs on version 1.6.1.

Logs:

verb app Initialising
info config Storing all data in http://flootr:secret@localhost:5984/
info hapi plugins registered
🐶  Your Hoodie app has started on: http://localhost:7777
Stop server with control + c
http response 2017-06-03T15:23:12.173Z - 127.0.0.1 - OPTIONS /hoodie/account/api/session/account 200 14ms
http response 2017-06-03T15:23:12.193Z - 127.0.0.1 - GET /hoodie/account/api/session/account 200 19ms
http response 2017-06-03T15:23:16.965Z - 127.0.0.1 - OPTIONS /hoodie/account/api/session 200 6ms
http response 2017-06-03T15:23:16.974Z - 127.0.0.1 - PUT /hoodie/account/api/session 201 11ms
http response 2017-06-03T15:23:16.993Z - 127.0.0.1 - OPTIONS /hoodie/store/api/user%2Fj5g7uip/?_nonce=1496503396991 200 7ms
http response 2017-06-03T15:23:17.006Z - 127.0.0.1 - GET /hoodie/store/api/user%2Fj5g7uip/?_nonce=1496503396991 200 39ms
http response 2017-06-03T15:23:17.048Z - 127.0.0.1 - OPTIONS /hoodie/store/api/?_nonce=1496503397045 200 5ms
http response 2017-06-03T15:23:17.055Z - 127.0.0.1 - OPTIONS /hoodie/store/api/?_nonce=1496503397045 200 19ms
http response 2017-06-03T15:23:17.069Z - 127.0.0.1 - GET /hoodie/store/api/?_nonce=1496503397045 404 11ms
http response 2017-06-03T15:23:17.081Z - 127.0.0.1 - GET /hoodie/store/api/?_nonce=1496503397045 404 4ms
http response 2017-06-03T15:23:18.440Z - 127.0.0.1 - OPTIONS /hoodie/store/api/?_nonce=1496503398437 200 5ms
http response 2017-06-03T15:23:18.448Z - 127.0.0.1 - GET /hoodie/store/api/?_nonce=1496503398437 404 5ms
http response 2017-06-03T15:23:18.815Z - 127.0.0.1 - OPTIONS /hoodie/store/api/?_nonce=1496503398813 200 5ms
http response 2017-06-03T15:23:18.823Z - 127.0.0.1 - GET /hoodie/store/api/?_nonce=1496503398813 404 6ms
http response 2017-06-03T15:23:21.073Z - 127.0.0.1 - OPTIONS /hoodie/store/api/?_nonce=1496503401071 200 5ms
http response 2017-06-03T15:23:21.082Z - 127.0.0.1 - GET /hoodie/store/api/?_nonce=1496503401071 404 4ms
http response 2017-06-03T15:23:21.450Z - 127.0.0.1 - OPTIONS /hoodie/store/api/?_nonce=1496503401448 200 4ms
http response 2017-06-03T15:23:21.459Z - 127.0.0.1 - GET /hoodie/store/api/?_nonce=1496503401448 404 3ms
http response 2017-06-03T15:23:25.520Z - 127.0.0.1 - OPTIONS /hoodie/store/api/?_nonce=1496503405517 200 2ms
http response 2017-06-03T15:23:25.525Z - 127.0.0.1 - GET /hoodie/store/api/?_nonce=1496503405517 404 2ms
http response 2017-06-03T15:23:26.625Z - 127.0.0.1 - OPTIONS /hoodie/store/api/?_nonce=1496503406623 200 3ms
http response 2017-06-03T15:23:26.631Z - 127.0.0.1 - GET /hoodie/store/api/?_nonce=1496503406623 404 2ms
http response 2017-06-03T15:23:26.751Z - 127.0.0.1 - OPTIONS /hoodie/account/api/session/account 200 5ms
http response 2017-06-03T15:23:26.759Z - 127.0.0.1 - GET /hoodie/account/api/session/account 200 3ms
http response 2017-06-03T15:23:27.627Z - 127.0.0.1 - OPTIONS /hoodie/store/api/user%2Fj5g7uip/?_nonce=1496503407624 200 3ms
http response 2017-06-03T15:23:27.632Z - 127.0.0.1 - GET /hoodie/store/api/user%2Fj5g7uip/?_nonce=1496503407624 200 6ms
http response 2017-06-03T15:23:27.641Z - 127.0.0.1 - OPTIONS /hoodie/store/api/?_nonce=1496503407639 200 3ms
http response 2017-06-03T15:23:27.646Z - 127.0.0.1 - GET /hoodie/store/api/?_nonce=1496503407639 404 2ms
http response 2017-06-03T15:23:27.651Z - 127.0.0.1 - OPTIONS /hoodie/store/api/user%2Fj5g7uip/_local/RtkUlWDGDSVvqfgCK2Gbbg==?_nonce=1496503407648 200 3ms
http response 2017-06-03T15:23:27.660Z - 127.0.0.1 - GET /hoodie/store/api/user%2Fj5g7uip/_local/RtkUlWDGDSVvqfgCK2Gbbg==?_nonce=1496503407648 200 8ms
http response 2017-06-03T15:23:27.674Z - 127.0.0.1 - OPTIONS /hoodie/store/api/user%2Fj5g7uip/_local/RtkUlWDGDSVvqfgCK2Gbbg==?_nonce=1496503407671 200 4ms
http response 2017-06-03T15:23:27.681Z - 127.0.0.1 - GET /hoodie/store/api/user%2Fj5g7uip/_local/RtkUlWDGDSVvqfgCK2Gbbg==?_nonce=1496503407671 200 9ms
http response 2017-06-03T15:23:27.695Z - 127.0.0.1 - OPTIONS /hoodie/account/api/session 200 4ms
http response 2017-06-03T15:23:27.700Z - 127.0.0.1 - DELETE /hoodie/account/api/session 204 3ms
http response 2017-06-03T15:23:33.328Z - 127.0.0.1 - OPTIONS /hoodie/store/api/?_nonce=1496503413324 200 2ms
http response 2017-06-03T15:23:33.333Z - 127.0.0.1 - GET /hoodie/store/api/?_nonce=1496503413324 404 1ms
http response 2017-06-03T15:23:33.618Z - 127.0.0.1 - OPTIONS /hoodie/store/api/?_nonce=1496503413614 200 2ms
http response 2017-06-03T15:23:33.622Z - 127.0.0.1 - GET /hoodie/store/api/?_nonce=1496503413614 404 2ms

gr2m commented 7 years ago

I was not able to reproduce the problem yet, do you use a custom app that is loaded from a different URL / port?

flootr commented 7 years ago

The app runs on localhost:8080.

I somehow (don't ask me how 😔) managed to have hoodie/pouchdb to use IndexedDB in my browser (latest Chrome) and the _nonce request failures are gone. However, the following still appear

GET http://localhost:7777/hoodie/store/api/user%2Fj5g7uip/_changes?timeout=25000&style=all_docs&feed=longpoll&heartbeat=10000&since=233&limit=100 net::ERR_INCOMPLETE_CHUNKED_ENCODING

(Note: If I copy the request url from the Network tab (copy as curl) and do it from the command line, it works just fine and resolves after changes come in.)

But I also get this net::ERR_INCOMPLETE_CHUNKED_ENCODING error for

GET http://localhost:8080/__webpack_hmr net::ERR_INCOMPLETE_CHUNKED_ENCODING

so this might be not related to hoodie/pouchdb at all. I need to investigate more.

flootr commented 7 years ago

I think I've found what caused the error: Node.js v8. If I switch back to 7.9.0 (or use the LTS version), no errors.

gr2m commented 7 years ago

thanks for the info! If you had a minimal reproducible test case that’d be much appreciated. Node 8 is stable now and Hoodie really should run smoothly with it

hoodiehq / hoodie

Heartbeat request failures after login #757