Fix new messages not appearing in chat list
.
- Fix new messages not appearing in chat list by serializing the
ObjectId
to a string in thebayeux-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
(fromgitter-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 Update: I verified I was using 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
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
(currentprod
) -> -
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 currentmaster
), reverted back to4.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