Fixes #122: add logging to inform user of Redis connection failure #553

Silvyre · 2020-01-19T21:38:08Z

Issue This PR Addresses

Fixes #122

Type of Change

Bugfix: Change which fixes an issue
New Feature: Change which adds functionality
Documentation Update: Change which improves documentation
UI: Change which improves UI

Description

As suggested in #48 (comment), added logic to handle 'ECONNREFUSED' errors within the Bull queue: 'ECONNREFUSED' are now logged an informative blurb instead of a stack trace.

https://github.com/Silvyre/telescope/blob/818ba4c9404f2cd5f2a70b7826a3650f1c215587/src/backend/lib/queue.js#L32-L43

Checklist

Quality: This PR builds and passes our npm test and works locally
Tests: This PR includes thorough tests or an explanation of why it does not
Screenshots: This PR includes screenshots or GIFs of the changes made or an explanation of why it does not (if applicable)
Documentation: This PR includes updated/added documentation to user exposed functionality or configuration variables are added/changed or an explanation of why it does not(if applicable)

src/backend/lib/queue.js

humphd · 2020-01-19T22:07:12Z

@yatsenko-julia I flagged you for review on this as well. Since you recently hit this issue yourself, could you try pulling @Silvyre's PR and testing it with your setup to see if you get the message?

humphd · 2020-01-19T22:16:27Z

I also tested this locally, and here is what I see, with Redis disabled on my Mac:

$ npm start

> telescope@0.0.1 start /Users/humphd/repos/telescope
> node src/backend

express-session deprecated req.secret; provide secret option src/backend/web/routes/login.js:17:12
[ 2020-01-19 17:14:20.536 ] INFO  (39125 on brightness.local): Telescope listening on port 3000
[ioredis] Unhandled error event: Error: connect ECONNREFUSED 127.0.0.1:6379
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1129:14)
[ 2020-01-19 17:14:20.605 ] ERROR (39125 on brightness.local):

	💡  It appears that Redis is not running on your machine.
	   Please see our documentation for how to install and run Redis:
	   https://github.com/Seneca-CDOT/telescope/blob/master/docs/CONTRIBUTING.md

[ 2020-01-19 17:14:20.606 ] ERROR (39125 on brightness.local): Queue feed-queue error
    err: {
      "type": "Error",
      "message": "Error initializing Lua scripts",
      "stack":
          Error: Error initializing Lua scripts
              at /Users/humphd/repos/telescope/node_modules/bull/lib/queue.js:155:30
              at processTicksAndRejections (internal/process/task_queues.js:93:5)
    }
[ 2020-01-19 17:14:20.608 ] ERROR (39125 on brightness.local):

	💡  It appears that Redis is not running on your machine.
	   Please see our documentation for how to install and run Redis:
	   https://github.com/Seneca-CDOT/telescope/blob/master/docs/CONTRIBUTING.md

[ 2020-01-19 17:14:20.619 ] INFO  (39125 on brightness.local): Received UNHANDLED REJECTION, starting shut down
[ 2020-01-19 17:14:20.619 ] ERROR (39125 on brightness.local):
    err: {
      "type": "Error",
      "message": "connect ECONNREFUSED 127.0.0.1:6379",
      "stack":
          Error: connect ECONNREFUSED 127.0.0.1:6379
              at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1129:14)
      "errno": "ECONNREFUSED",
      "code": "ECONNREFUSED",
      "syscall": "connect",
      "address": "127.0.0.1",
      "port": 6379
    }
[ 2020-01-19 17:14:20.621 ] INFO  (39125 on brightness.local): Web server shut down.
[ 2020-01-19 17:14:20.621 ] INFO  (39125 on brightness.local): Feed queue shut down.
[ 2020-01-19 17:14:20.621 ] INFO  (39125 on brightness.local): Completing shut down.

@Silvyre, your message happens multiple times. Do you think it might be possible to get this to only happen once? If it scrolls off the screen, it loses some of its value.

Silvyre · 2020-01-19T22:20:22Z

@Silvyre, your message happens multiple times. Do you think it might be possible to get this to only happen once? If it scrolls off the screen, it loses some of its value.

Looking into this!

Silvyre · 2020-01-19T22:26:26Z

@Silvyre, your message happens multiple times. Do you think it might be possible to get this to only happen once? If it scrolls off the screen, it loses some of its value.

Looking into this!

@humphd How's this? I added a simple check to ensure the message is logged only once: 1a6c56e

src/backend/lib/queue.js

cindyorangis

I've checked this PR and the message only appears once as we wanted. I can give an approving review after you've made changes addressed by @humphd :)

[cindy@localhost telescope]$ npm start

> telescope@0.0.1 start /home/cindy/Documents/Projects/telescope
> node src/backend

[ 2020-01-20 18:09:15.686 ] INFO  (2996 on localhost.localdomain): Telescope listening on port 3000
[ioredis] Unhandled error event: Error: connect ECONNREFUSED 127.0.0.1:6379
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1129:14)
[ 2020-01-20 18:09:15.696 ] ERROR (2996 on localhost.localdomain): 

        💡  It appears that Redis is not running on your machine. 
           Please see our documentation for how to install and run Redis: 
           https://github.com/Seneca-CDOT/telescope/blob/master/docs/CONTRIBUTING.md

[ 2020-01-20 18:09:15.697 ] ERROR (2996 on localhost.localdomain): Queue feed-queue error
    err: {
      "type": "Error",
      "message": "Error initializing Lua scripts",
      "stack":
          Error: Error initializing Lua scripts
              at /home/cindy/Documents/Projects/telescope/node_modules/bull/lib/queue.js:155:30
              at processTicksAndRejections (internal/process/task_queues.js:93:5)
    }
[ 2020-01-20 18:09:15.699 ] INFO  (2996 on localhost.localdomain): Received UNHANDLED REJECTION, starting shut down
[ 2020-01-20 18:09:15.699 ] ERROR (2996 on localhost.localdomain):
    err: {
      "type": "Error",
      "message": "connect ECONNREFUSED 127.0.0.1:6379",
      "stack":
          Error: connect ECONNREFUSED 127.0.0.1:6379
              at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1129:14)
      "errno": "ECONNREFUSED",
      "code": "ECONNREFUSED",
      "syscall": "connect",
      "address": "127.0.0.1",
      "port": 6379
    }
[ 2020-01-20 18:09:15.700 ] INFO  (2996 on localhost.localdomain): Web server shut down.
[ 2020-01-20 18:09:15.701 ] INFO  (2996 on localhost.localdomain): Feed queue shut down.
[ 2020-01-20 18:09:15.701 ] INFO  (2996 on localhost.localdomain): Completing shut down.

yatsenko-julia · 2020-01-21T12:22:20Z

I am not sure why but I've got a different message. Here it is:

$ npm start

> telescope@0.0.1 start /Users/julia-yatsenko/Downloads/telescope-master
> node src/backend

internal/modules/cjs/loader.js:796
    throw err;
    ^

Error: Cannot find module 'dotenv'
Require stack:
- /Users/julia-yatsenko/Downloads/telescope-master/src/backend/lib/config.js
- /Users/julia-yatsenko/Downloads/telescope-master/src/backend/index.js
    at Function.Module._resolveFilename (internal/modules/cjs/loader.js:793:17)
    at Function.Module._load (internal/modules/cjs/loader.js:686:27)
    at Module.require (internal/modules/cjs/loader.js:848:19)
    at require (internal/modules/cjs/helpers.js:74:18)
    at Object.<anonymous> (/Users/julia-yatsenko/Downloads/telescope-master/src/backend/lib/config.js:1:16)
    at Module._compile (internal/modules/cjs/loader.js:955:30)
    at Object.Module._extensions..js (internal/modules/cjs/loader.js:991:10)
    at Module.load (internal/modules/cjs/loader.js:811:32)
    at Function.Module._load (internal/modules/cjs/loader.js:723:14)
    at Module.require (internal/modules/cjs/loader.js:848:19) {
  code: 'MODULE_NOT_FOUND',
  requireStack: [
    '/Users/julia-yatsenko/Downloads/telescope-master/src/backend/lib/config.js',
    '/Users/julia-yatsenko/Downloads/telescope-master/src/backend/index.js'
  ]
}
npm ERR! code ELIFECYCLE
npm ERR! errno 1
npm ERR! telescope@0.0.1 start: `node src/backend`
npm ERR! Exit status 1
npm ERR! 
npm ERR! Failed at the telescope@0.0.1 start script.
npm ERR! This is probably not a problem with npm. There is likely additional logging output above.
npm WARN Local package.json exists, but node_modules missing, did you mean to install?

humphd · 2020-01-21T13:22:17Z

@yatsenko-julia that likely means npm install hasn't been run, or hasn't completed successfully. Try this:

rm -fr node_modules
npm install
npm start

yatsenko-julia · 2020-01-21T13:29:15Z

@humphd Thank you! Now it works.

humphd

Looks good to me.

Seneca-CDOT#122 add descriptive logging when ECONNREFUSED

818ba4c

Silvyre added the area: redis Redis Database related label Jan 19, 2020

Silvyre self-assigned this Jan 19, 2020

humphd requested changes Jan 19, 2020

View reviewed changes

src/backend/lib/queue.js Outdated Show resolved Hide resolved

src/backend/lib/queue.js Show resolved Hide resolved

humphd requested a review from yatsenko-julia January 19, 2020 22:06

Change ECONNREFUSED logging from info to error

ffcebe5

Ensure redis connection error is logged only once

1a6c56e

manekenpix requested a review from humphd January 20, 2020 15:09

humphd requested changes Jan 20, 2020

View reviewed changes

src/backend/lib/queue.js Outdated Show resolved Hide resolved

src/backend/lib/queue.js Outdated Show resolved Hide resolved

cindyorangis requested changes Jan 20, 2020

View reviewed changes

yatsenko-julia previously approved these changes Jan 21, 2020

View reviewed changes

rename redisNotAvailableLogged, simplify conditional logic

16b6007

Silvyre dismissed yatsenko-julia’s stale review via 16b6007 January 21, 2020 17:57

Silvyre requested review from yatsenko-julia, cindyorangis and humphd January 21, 2020 18:00

humphd approved these changes Jan 21, 2020

View reviewed changes

yatsenko-julia approved these changes Jan 21, 2020

View reviewed changes

humphd merged commit 5e5ee68 into Seneca-CDOT:master Jan 22, 2020

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Fixes #122: add logging to inform user of Redis connection failure #553

Fixes #122: add logging to inform user of Redis connection failure #553

Silvyre commented Jan 19, 2020

humphd commented Jan 19, 2020

humphd commented Jan 19, 2020

Silvyre commented Jan 19, 2020

Silvyre commented Jan 19, 2020 •

edited

Loading

cindyorangis left a comment

yatsenko-julia commented Jan 21, 2020

humphd commented Jan 21, 2020

yatsenko-julia commented Jan 21, 2020

humphd left a comment

Fixes #122: add logging to inform user of Redis connection failure #553

Fixes #122: add logging to inform user of Redis connection failure #553

Conversation

Silvyre commented Jan 19, 2020

Issue This PR Addresses

Type of Change

Description

Checklist

humphd commented Jan 19, 2020

humphd commented Jan 19, 2020

Silvyre commented Jan 19, 2020

Silvyre commented Jan 19, 2020 • edited Loading

cindyorangis left a comment

Choose a reason for hiding this comment

yatsenko-julia commented Jan 21, 2020

humphd commented Jan 21, 2020

yatsenko-julia commented Jan 21, 2020

humphd left a comment

Choose a reason for hiding this comment

Silvyre commented Jan 19, 2020 •

edited

Loading