[BUG] Syslog and daemon.log fill-up with exceptions: sanitizedError: errorClass [Error]: Match failed [400]

Description:

Our /var/syslog and /var/daemon.log started filling up with lots of exceptions recently. Those grew to 7GB and 19GB in a single day:

root@pi1145:/var/log# ls -alh -sh syslog*
5.3G -rw-r----- 1 root adm 5.3G Jul 30 12:25 syslog
6.8G -rw-r----- 1 root adm 6.8G Jul 29 06:25 syslog.1
8.0K -rw-r----- 1 root adm 5.9K Jul 28 06:25 syslog.2.gz
8.0K -rw-r----- 1 root adm 5.8K Jul 27 06:25 syslog.3.gz
8.0K -rw-r----- 1 root adm 5.1K Jul 26 06:25 syslog.4.gz
4.0K -rw-r----- 1 root adm 4.0K Jul 25 06:25 syslog.5.gz
8.0K -rw-r----- 1 root adm 5.0K Jul 24 06:25 syslog.6.gz
 32K -rw-r----- 1 root adm  29K Jul 23 06:25 syslog.7.gz

These exceptions are spammed in syslog:

Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]: Exception on find errorClass [Error]: Match error: Failed Match.OneOf, Match.Maybe or Match.Optional validation
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:     at check (packages/check/match.js:36:17)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:     at ns.Collection._getFindOptions (packages/mongo/collection.js:295:7)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:     at ns.Collection.find (packages/mongo/collection.js:336:12)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:     at BaseDb.find (app/models/server/models/_BaseDb.js:177:21)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:     at Messages.find (app/models/server/models/_Base.js:106:29)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:     at Messages.findVisibleByRoomIdBetweenTimestampsNotContainingTypes (app/models/server/models/Messages.js:374:15)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:     at MethodInvocation.getChannelHistory (app/lib/server/methods/getChannelHistory.js:56:15)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:     at MethodInvocation.methodsMap.<computed> (app/lib/server/lib/debug.js:76:34)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:     at maybeAuditArgumentChecks (packages/ddp-server/livedata_server.js:1771:12)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:     at packages/ddp-server/livedata_server.js:1689:15
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:     at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:     at packages/ddp-server/livedata_server.js:1687:36
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:     at new Promise (<anonymous>)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:     at Server.applyAsync (packages/ddp-server/livedata_server.js:1686:12)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:     at Server.apply (packages/ddp-server/livedata_server.js:1625:26)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:     at Server.call (packages/ddp-server/livedata_server.js:1607:17)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:     at Object.get (app/api/server/v1/channels.js:392:25)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:     at app/api/server/api.js:394:82
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:     at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:     at Object._internalRouteActionHandler [as action] (app/api/server/api.js:394:39)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:     at Route.share.Route.Route._callEndpoint (packages/nimble_restivus/lib/route.coffee:150:32)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:     at packages/nimble_restivus/lib/route.coffee:59:33
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:     at packages/simple_json-routes.js:98:9 {
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:   path: '',
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:   sanitizedError: errorClass [Error]: Match failed [400]
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:       at errorClass.<anonymous> (packages/check/match.js:91:27)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:       at new errorClass (packages/meteor.js:655:17)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:       at check (packages/check/match.js:36:17)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:       at ns.Collection._getFindOptions (packages/mongo/collection.js:295:7)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:       at ns.Collection.find (packages/mongo/collection.js:336:12)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:       at BaseDb.find (app/models/server/models/_BaseDb.js:177:21)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:       at Messages.find (app/models/server/models/_Base.js:106:29)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:       at Messages.findVisibleByRoomIdBetweenTimestampsNotContainingTypes (app/models/server/models/Messages.js:374:15)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:       at MethodInvocation.getChannelHistory (app/lib/server/methods/getChannelHistory.js:56:15)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:       at MethodInvocation.methodsMap.<computed> (app/lib/server/lib/debug.js:76:34)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:       at maybeAuditArgumentChecks (packages/ddp-server/livedata_server.js:1771:12)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:       at packages/ddp-server/livedata_server.js:1689:15
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:       at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:       at packages/ddp-server/livedata_server.js:1687:36
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:       at new Promise (<anonymous>)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:       at Server.applyAsync (packages/ddp-server/livedata_server.js:1686:12)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:       at Server.apply (packages/ddp-server/livedata_server.js:1625:26)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:       at Server.call (packages/ddp-server/livedata_server.js:1607:17)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:       at Object.get (app/api/server/v1/channels.js:392:25)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:       at app/api/server/api.js:394:82
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:       at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:       at Object._internalRouteActionHandler [as action] (app/api/server/api.js:394:39)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:       at Route.share.Route.Route._callEndpoint (packages/nimble_restivus/lib/route.coffee:150:32)
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:       at packages/nimble_restivus/lib/route.coffee:59:33
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:       at packages/simple_json-routes.js:98:9 {
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:     isClientSafe: true,
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:     error: 400,
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:     reason: 'Match failed',
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:     details: undefined,
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:     errorType: 'Meteor.Error'
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:   },
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]:   errorType: 'Match.Error'
Jul 29 06:25:23 pi1145 rocketchat-server.rocketchat-server[31056]: } {

and these in /var/daemon.log

Jul 30 12:30:44 pi1145 rocketchat-server.rocketchat-server[31056]: Exception on find errorClass [Error]: Match error: Failed Match.OneOf, Match.Maybe or Match.Optional validation
Jul 30 12:30:44 pi1145 rocketchat-server.rocketchat-server[31056]:     at check (packages/check/match.js:36:17)
Jul 30 12:30:44 pi1145 rocketchat-server.rocketchat-server[31056]:     at ns.Collection._getFindOptions (packages/mongo/collection.js:295:7)
Jul 30 12:30:44 pi1145 rocketchat-server.rocketchat-server[31056]:     at ns.Collection.find (packages/mongo/collection.js:336:12)
Jul 30 12:30:44 pi1145 rocketchat-server.rocketchat-server[31056]:     at BaseDb.find (app/models/server/models/_BaseDb.js:177:21)
Jul 30 12:30:44 pi1145 rocketchat-server.rocketchat-server[31056]:     at Messages.find (app/models/server/models/_Base.js:106:29)
Jul 30 12:30:44 pi1145 rocketchat-server.rocketchat-server[31056]:     at Messages.findVisibleByRoomIdBetweenTimestampsNotContainingTypes (app/models/server/models/Messages.js:374:15)
Jul 30 12:30:44 pi1145 rocketchat-server.rocketchat-server[31056]:     at MethodInvocation.getChannelHistory (app/lib/server/methods/getChannelHistory.js:56:15)
Jul 30 12:30:44 pi1145 rocketchat-server.rocketchat-server[31056]:     at MethodInvocation.methodsMap.<computed> (app/lib/server/lib/debug.js:76:34)
Jul 30 12:30:44 pi1145 rocketchat-server.rocketchat-server[31056]:     at maybeAuditArgumentChecks (packages/ddp-server/livedata_server.js:1771:12)
Jul 30 12:30:44 pi1145 rocketchat-server.rocketchat-server[31056]:     at packages/ddp-server/livedata_server.js:1689:15
Jul 30 12:30:44 pi1145 rocketchat-server.rocketchat-server[31056]:     at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12)
Jul 30 12:30:44 pi1145 rocketchat-server.rocketchat-server[31056]:     at packages/ddp-server/livedata_server.js:1687:36
Jul 30 12:30:44 pi1145 rocketchat-server.rocketchat-server[31056]:     at new Promise (<anonymous>)
Jul 30 12:30:44 pi1145 rocketchat-server.rocketchat-server[31056]:     at Server.applyAsync (packages/ddp-server/livedata_server.js:1686:12)
Jul 30 12:30:44 pi1145 rocketchat-server.rocketchat-server[31056]:     at Server.apply (packages/ddp-server/livedata_server.js:1625:26)
Jul 30 12:30:44 pi1145 rocketchat-server.rocketchat-server[31056]:     at Server.call (packages/ddp-server/livedata_server.js:1607:17)
Jul 30 12:30:44 pi1145 rocketchat-server.rocketchat-server[31056]:     at Object.get (app/api/server/v1/im.js:181:25)
Jul 30 12:30:44 pi1145 rocketchat-server.rocketchat-server[31056]:     at app/api/server/api.js:394:82
Jul 30 12:30:44 pi1145 rocketchat-server.rocketchat-server[31056]:     at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12)
Jul 30 12:30:44 pi1145 rocketchat-server.rocketchat-server[31056]:     at Object._internalRouteActionHandler (app/api/server/api.js:394:39)
Jul 30 12:30:44 pi1145 rocketchat-server.rocketchat-server[31056]:     at app/api/server/api.js:394:82
Jul 30 12:30:44 pi1145 rocketchat-server.rocketchat-server[31056]:     at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12)
Jul 30 12:30:44 pi1145 rocketchat-server.rocketchat-server[31056]:     at Object._internalRouteActionHandler [as action] (app/api/server/api.js:394:39)
Jul 30 12:30:44 pi1145 rocketchat-server.rocketchat-server[31056]:     at Route.share.Route.Route._callEndpoint (packages/nimble_restivus/lib/route.coffee:150:32)
Jul 30 12:30:44 pi1145 rocketchat-server.rocketchat-server[31056]:     at packages/nimble_restivus/lib/route.coffee:59:33
Jul 30 12:30:44 pi1145 rocketchat-server.rocketchat-server[31056]:     at packages/simple_json-routes.js:98:9 {
Jul 30 12:30:44 pi1145 rocketchat-server.rocketchat-server[31056]:   path: '',

Server Setup Information:

• Version of Rocket.Chat Server: 3.16.3
• Operating System: Debian Buster
• Deployment Method: snap
• Number of Running Instances: 1
• DB Replicaset Oplog:
• NodeJS Version: v12.22.1
• MongoDB Version: 3.6.14 / wiredTiger (oplog Enabled)

Client Setup Information

• Desktop App or Browser Version: 3.0.3
• Operating System: macOS

Additional context

Relevant logs:

Start with app/models/server/models/Messages.js at findVisibleByRoomIdBetweenTimestampsNotContainingTypes and app/models/server/models/_BaseDb.js, then trace callers in getChannelHistory.js, channels.js, and im.js. Reproduce the Match validation failure through the affected history endpoints and identify the invalid find options. Done means the requests complete without repeated exceptions filling syslog or daemon.log.