Fix new messages not appearing in chat list

.

• Fix new messages not appearing in chat list by serializing the ObjectId to a string in the bayeux-events-bridge before publishing it to faye
• Update faye/bayeux-cluster logging to actually log fatal errors and report errors
• Adds npm start -- --inspect-node so you debug with familiar browser devtools and step through the code
• Update @gitterhq/env@0.34.0 for https://gitlab.com/gitlab-org/gitter/env/merge_requests/10
• Update @gitterhq/faye@1.1.0-j(from gitter-faye) for https://gitlab.com/gitlab-org/gitter/faye/merge_requests/1

Investigation

Redis

I looked directly at the Redis store to make sure the subscriptions were being saved and accounted for

$ npm install redis-commander -g
$ redis-commander
# Visit http://localhost:8081/
# Look at the `fr:` prefixed entries (defined here, https://gitlab.com/gitlab-org/gitter/webapp/blob/c3b8126074edaef9c20793c4d910e9f4c1720aa9/server/web/bayeux/cluster.js#L45)

Websocket/faye server

I could see that there wasn't any .../chatMessages frames client-side. When things are working normally, we get a downstream frame that looks like this,

[
  {
    "channel": "/api/v1/rooms/556b681e15522ed4b3e1357f/chatMessages",
    "data": {
      "operation": "create",
      "model": {
        "id": "5af09cf797f07c7e13768675",
        "text": "nnbn",
        "html": "nnbn",
        "sent": "2018-05-07T18:37:43.077Z",
        "fromUser": {
          "id": "55b214df0fc9f982beaad275",
          "username": "EricTroupeTester",
          "displayName": "Eric Eastwood",
          "url": "/EricTroupeTester",
          "avatarUrl": "https://avatars-03.gitter.im/gh/uv/4/EricTroupeTester",
          "avatarUrlSmall": "https://avatars1.githubusercontent.com/u/13482600?v=4&s=60",
          "avatarUrlMedium": "https://avatars1.githubusercontent.com/u/13482600?v=4&s=128",
          "v": 183,
          "gv": "4"
        },
        "unread": true,
        "readBy": 0,
        "urls": [],
        "mentions": [],
        "issues": [],
        "meta": [],
        "v": 1
      }
    },
    "id": "5c47",
    "ext": {
      "c": 7
    }
  }
]

I was able to debug that websocket frames weren't getting sent from the server with the faye monitoring hooks. There wasn't any publish .../chatMessages when a message was sent.

Add to server/web/bayeux/cluster.js

/* */
server.on('handshake', function(clientId) {
  console.log(`handshake: ${clientId}`);
});
server.on('subscribe', function(clientId, channel) {
  console.log(`subscribe: ${clientId} ${channel}`);
});
server.on('unsubscribe', function(clientId, channel) {
  console.log(`unsubscribe: ${clientId} ${channel}`);
});
server.on('publish', function(clientId, channel, data) {
  console.log(`publish: ${clientId} ${channel} ${JSON.stringify(data)}`);
});
server.on('disconnect', function(clientId) {
  console.log(`disconnect: ${clientId}`);
});
/* */

mongoose dependency

From some debugging, it looks like the mongoose schema.post('save', ...) hooks are not firing.

Relevant code: modules/persistence-utils/lib/mongoose-utils.js#L73-77-> server/services/persistence-service-events.js#L29-33

There is an issue around hooks that @andrewn created for mongoose@>=4.8.0 but we are using mongoose@4.6.8 😕

---

Testing locally, I am seeing our tests around the hook functionality is failing with mongoose@4.6.8, modules/persistence-utils/test/mongoose-utils-test.js. You can try it out npm run mocha -- modules/persistence-utils/test/mongoose-utils-test.js Update: I verified I was using mongoose@4.6.8 previously and now but now it is all of the sudden working 🤔

But it appears to pass in CI, https://gitlab.com/gitlab-org/gitter/webapp/-/jobs/66957916 (search for attachNotificationListenersToSchema)

---

mongoose dependency progression

• mongoose@4.5.3 (current prod) ->
• mongoose@4.10.8(https://gitlab.com/gitlab-org/gitter/webapp/merge_requests/1064) ->
• mongoose4.6.8(https://gitlab.com/gitlab-org/gitter/webapp/merge_requests/1067 and current master), reverted back to 4.6.8 because of https://github.com/Automattic/mongoose/issues/5438

Back to the Websocket/faye server

The following errors were being hidden away because we didn't have proper logging setup. I'm not sure what caused the change where trying to JSON.stringify(someMongooseModel) will throw errors about the ObjectId buffers. There has been various updates to BSON things in mongo@2.2.x, https://github.com/mongodb/node-mongodb-native/blob/344d1f5a18291a262e74f0addb40710f4d443926/HISTORY.md

Related issue, https://github.com/winstonjs/winston-mongodb/issues/85

Error: invalid ObjectId, ObjectId.id must be either a string or a Buffer, but is [{"type":"Buffer","data":[]}]
	at ObjectID.toHexString (gitlab\webapp\node_modules\mongoose\node_modules\bson\lib\bson\objectid.js:73:11)
	at ObjectID.toJSON (gitlab\webapp\node_modules\mongoose\node_modules\bson\lib\bson\objectid.js:174:15)
	at Object.stringify (native)
	at Object.publish (gitlab\webapp\node_modules\@gitterhq\faye-redis\faye-redis.js:270:28)
	at Object.publish (gitlab\webapp\node_modules\gitter-faye\javascript\engines\proxy.js:108:25)
	at Object._handle (gitlab\webapp\node_modules\gitter-faye\javascript\protocol\server.js:109:30)
	at Object.<anonymous> (gitlab\webapp\node_modules\gitter-faye\javascript\protocol\server.js:78:14)
	at pipe (gitlab\webapp\node_modules\gitter-faye\javascript\protocol\extensible.js:33:39)
	at pipe (gitlab\webapp\node_modules\gitter-faye\javascript\protocol\extensible.js:36:23)
	at pipe (gitlab\webapp\node_modules\gitter-faye\javascript\protocol\extensible.js:36:23)
	at Object.extension.incoming (gitlab/webapp/server/web/bayeux/extension.js:66:16)
	at pipe (gitlab\webapp\node_modules\gitter-faye\javascript\protocol\extensible.js:38:43)
	at Object.extension.incoming (gitlab/webapp/server/web/bayeux/extension.js:66:16)
	at pipe (gitlab\webapp\node_modules\gitter-faye\javascript\protocol\extensible.js:38:43)
	at Object.extension.incoming (gitlab/webapp/server/web/bayeux/extension.js:66:16)
	at pipe (gitlab\webapp\node_modules\gitter-faye\javascript\protocol\extensible.js:38:43)
	at Object.extension.incoming (gitlab/webapp/server/web/bayeux/extension.js:70:16)
	at pipe (gitlab\webapp\node_modules\gitter-faye\javascript\protocol\extensible.js:38:43)
	at Object.incoming (gitlab/webapp/server/web/bayeux/logging.js:45:5)
	at pipe (gitlab\webapp\node_modules\gitter-faye\javascript\protocol\extensible.js:38:43)
	at Object.pipeThroughExtensions (gitlab\webapp\node_modules\gitter-faye\javascript\protocol\extensible.js:41:5)
	at Object.process (gitlab\webapp\node_modules\gitter-faye\javascript\protocol\server.js:77:12)
	at Object.request (gitlab\webapp\node_modules\gitter-faye\javascript\transport\node_local.js:13:19)
	at Object.sendMessage (gitlab\webapp\node_modules\gitter-faye\javascript\transport\transport.js:41:60)
	at Object._sendEnvelope (gitlab\webapp\node_modules\gitter-faye\javascript\protocol\dispatcher.js:128:40)
	at Object.sendMessage (gitlab\webapp\node_modules\gitter-faye\javascript\protocol\dispatcher.js:106:10)
	at Object.<anonymous> (gitlab\webapp\node_modules\gitter-faye\javascript\protocol\client.js:341:24)
	at pipe (gitlab\webapp\node_modules\gitter-faye\javascript\protocol\extensible.js:33:39)
	at Object.outgoing (gitlab/webapp/server/web/bayeux/super-client.js:12:5)
	at pipe (gitlab\webapp\node_modules\gitter-faye\javascript\protocol\extensible.js:39:43)
	at Object.pipeThroughExtensions (gitlab\webapp\node_modules\gitter-faye\javascript\protocol\extensible.js:41:5)
	at Object._sendMessage (gitlab\webapp\node_modules\gitter-faye\javascript\protocol\client.js:334:10)
	at Object.<anonymous> (gitlab\webapp\node_modules\gitter-faye\javascript\protocol\client.js:299:12)
	at gitlab\webapp\node_modules\gitter-faye\javascript\mixins\deferrable.js:22:49
	at _invoke (gitlab\webapp\node_modules\gitter-faye\javascript\util\promise.js:70:15)
	at Immediate.<anonymous> (gitlab\webapp\node_modules\gitter-faye\javascript\util\promise.js:63:22)
	at runCallback (timers.js:672:20)
	at tryOnImmediate (timers.js:645:5)
	at processImmediate [as _immediateCallback] (timers.js:617:5)

Error: invalid ObjectId, ObjectId.id must be either a string or a Buffer, but is [{"type":"Buffer","data":[]}]
	at ObjectID.toHexString (C:\\Users\\MLM\\Documents\\GitLab\\webapp\\node_modules\\mongoose\\node_modules\\bson\\lib\\bson\\objectid.js:73:11)
	at ObjectID.toJSON (C:\\Users\\MLM\\Documents\\GitLab\\webapp\\node_modules\\mongoose\\node_modules\\bson\\lib\\bson\\objectid.js:174:15)
	at Object.stringify (native)
	at stringifyInternal (gitlab/webapp/server/web/bayeux/cluster.js:141:21)
	at Object.faye.stringify (gitlab/webapp/server/web/bayeux/cluster.js:157:12)
	at Object.toJSON (gitlab/gitter-faye/javascript/faye.js:130:17)
	at gitlab/gitter-faye/javascript/mixins/logging.js:25:25
	at RegExp.[Symbol.replace] (native)
	at RegExp.[Symbol.replace] (native)
	at String.replace (native)
	at Object.writeLog (gitlab/gitter-faye/javascript/mixins/logging.js:23:32)
	at Object.Faye_Logging.(anonymous function) [as debug] (gitlab/gitter-faye/javascript/mixins/logging.js:50:14)
	at Object.publish (gitlab/gitter-faye-redis/faye-redis.js:268:18)
	at Object.publish (gitlab/gitter-faye/javascript/engines/proxy.js:109:25)
	at Object._handle (gitlab/gitter-faye/javascript/protocol/server.js:109:30)
	at Object.<anonymous> (gitlab/gitter-faye/javascript/protocol/server.js:78:14)
	at pipe (gitlab/gitter-faye/javascript/protocol/extensible.js:32:39)
	at pipe (gitlab/gitter-faye/javascript/protocol/extensible.js:35:23)
	at pipe (gitlab/gitter-faye/javascript/protocol/extensible.js:35:23)
	at Object.extension.incoming (gitlab/webapp/server/web/bayeux/extension.js:66:16)
	at pipe (gitlab/gitter-faye/javascript/protocol/extensible.js:37:27)
	at Object.extension.incoming (gitlab/webapp/server/web/bayeux/extension.js:66:16)
	at pipe (gitlab/gitter-faye/javascript/protocol/extensible.js:37:27)
	at Object.extension.incoming (gitlab/webapp/server/web/bayeux/extension.js:66:16)
	at pipe (gitlab/gitter-faye/javascript/protocol/extensible.js:37:27)
	at Object.extension.incoming (gitlab/webapp/server/web/bayeux/extension.js:70:16)
	at pipe (gitlab/gitter-faye/javascript/protocol/extensible.js:37:27)
	at Object.incoming (gitlab/webapp/server/web/bayeux/logging.js:45:5)
	at pipe (gitlab/gitter-faye/javascript/protocol/extensible.js:37:27)
	at Object.pipeThroughExtensions (gitlab/gitter-faye/javascript/protocol/extensible.js:40:5)
	at Object.process (gitlab/gitter-faye/javascript/protocol/server.js:77:12)
	at Object.request (gitlab/gitter-faye/javascript/transport/node_local.js:13:19)
	at Object.sendMessage (gitlab/gitter-faye/javascript/transport/transport.js:41:60)
	at Object._sendEnvelope (gitlab/gitter-faye/javascript/protocol/dispatcher.js:128:40)
	at Object.sendMessage (gitlab/gitter-faye/javascript/protocol/dispatcher.js:106:10)
	at Object.<anonymous> (gitlab/gitter-faye/javascript/protocol/client.js:331:24)
	at pipe (gitlab/gitter-faye/javascript/protocol/extensible.js:32:39)
	at Object.outgoing (gitlab/webapp/server/web/bayeux/super-client.js:12:5)
	at pipe (gitlab/gitter-faye/javascript/protocol/extensible.js:38:27)
	at Object.pipeThroughExtensions (gitlab/gitter-faye/javascript/protocol/extensible.js:40:5)
	at Object._sendMessage (gitlab/gitter-faye/javascript/protocol/client.js:328:10)
	at Object.<anonymous> (gitlab/gitter-faye/javascript/protocol/client.js:298:12)
	at gitlab/gitter-faye/javascript/mixins/deferrable.js:22:49
	at _invoke (gitlab/gitter-faye/javascript/util/promise.js:70:15)
	at Immediate.<anonymous> (gitlab/gitter-faye/javascript/util/promise.js:63:22)
	at runCallback (timers.js:672:20)
	at tryOnImmediate (timers.js:645:5)
	at processImmediate [as _immediateCallback] (timers.js:617:5)

---

Closes https://gitlab.com/gitlab-org/gitter/webapp/issues/1894