search

RocketChat / Rocket.Chat

The communications platform that puts data protection first.
https://rocket.chat/
Other
40.8k stars 10.72k forks source link

Non standard syslog message (size too large) #19165

Open Nono-m0le opened 4 years ago

Nono-m0le commented 4 years ago

Description:

On some case (mainly when an user is uploading/sending a file to someone else, it generates an non-standard/too large log to syslog.

Steps to reproduce:

Install RC using SNAP package Upload files (long name) See huge single line message on /var/log/syslog

Expected behavior:

Log into dedicated files (ie: /var/log/rocketchat/error.log) or Anonymized logs / shortener / on multiple line instead of one long

Actual behavior:

Exemple of log: Oct 7 16:39:12 server rocketchat-server.rocketchat-mongo[698]: 2020-10-07T16:39:12.658+0200 I COMMAND [conn10] command parties.rocketchat_message command: insert { insert: "rocketchat_message", documents: [ { _id: "XXXXX", rid: "XXXXX", ts: new Date(1602081552281), msg: "", file: { _id: "SiHXmcoisRi9zRovu", name: "filename_quite_long_but_still_normal.zip", type: "application/x-zip-compressed" }, groupable: false, attachments: [ { title: "filename_quite_long_but_still_normal.zip", type: "file", title_link: "/file-upload/xxxx/filename_quite_long_but_still_normal.zip", title_link_download: true } ], u: { _id: "xxxxx", username: "User1" }, mentions: [], channels: [], _updatedAt: new Date(1602081552337) } ], ordered: true, lsid: { id: UUID("xxxxx") }, $clusterTime: { clusterTime: Timestamp(1602081552, 3), signature: { hash: BinData(0, 0000000000000000000000000000000000000000), keyId: 0 } }, $db: "parties" } ninserted:1 keysInserted:8 numYields:0 reslen:214 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_msg 309ms

Server Setup Information:

Client Setup Information

Nono-m0le commented 4 years ago

Hi @frdmn any news on this ? I'm still getting those quite often.

Nono-m0le commented 4 years ago

It seems that (among others), removing a message also generate this kind of unsupported syslog messages:

Nov  9 08:30:02 server rocketchat-server.rocketchat-mongo[698]:
2020-11-09T08:30:02.257+0100 I WRITE    [conn6] remove
parties.rocketchat_message command: { q: { _id: { $in: [
"dRhETvhGxxYJ2fX8v", "HusbQEjBxx7nKj6hK", "vZ9PknkxxYFzAYc72M",
"zPLbCwYxxx4TAC386", "EyzHYt3xxx9pxinJW", "sTMoPX2RyJWEZgz3G",
"jGBDKfHDxx6ZZzvEg", "fftAHzxxxCdm4TvyC", "zMvHrwxxtYvAvT9he",
"KdX3bZzxxDKGjn8dP", "nwLwQPfCDximLrEia", "JdTxKFjxyHudZcMfd",
"PQn92gpkqmxdhnfJp", "RmWjqgA2exxE5r9EE", "eZd3x5rxxxZdo9yKp",
"Y5XSBxxxxYqsWzmGd", "tYByNe4xx9fXKa7BN", "Du94tjwxxT5rXKpay",
"5WybpRaxxzP6b35Ay", "mrcnaaxxxx7EmTRzH", "Fb33axxxxHToRXeba",
"zKQkqSXKrxxxknvsn", "iQ3YLSA7pmxxD63TX", "gpnkGFxxxepJpt6CY",
"GmGDqeSfK7LcxxWux", "6u8cDCtxxxkvQZvPf", "f7Qxxh6t3mqrszC8R",
"y6kMxxxcaa6YmgzqC", "ptHdCvTYcC8xxxmc6", "PmKkemWxxxLY2pRQo" ] } },
limit: 0 } planSummary: IXSCAN { _id: 1 } keysExamined:60
docsExamined:30 ndeleted:30 keysDeleted:336 numYields:6 locks:{ Global:
{ acquireCount: { r: 37, w: 37 } }, Database: { acquireCount: { w: 37 }
}, Collection: { acquireCount: { w: 7 } }, oplog: { acquireCount: { w:
30 } } } 145ms

Nov  9 08:30:02 server rocketchat-server.rocketchat-mongo[698]:
2020-11-09T08:30:02.259+0100 I COMMAND  [conn6] command parties.$cmd
command: delete { delete: "rocketchat_message", deletes: [ { q: { _id:
{ $in: [ ""dRhETvhGxxYJ2fX8v", "HusbQEjBxx7nKj6hK", "vZ9PknkxxYFzAYc72M",
"zPLbCwYxxx4TAC386", "EyzHYt3xxx9pxinJW", "sTMoPX2RyJWEZgz3G",
"jGBDKfHDxx6ZZzvEg", "fftAHzxxxCdm4TvyC", "zMvHrwxxtYvAvT9he",
"KdX3bZzxxDKGjn8dP", "nwLwQPfCDximLrEia", "JdTxKFjxyHudZcMfd",
"PQn92gpkqmxdhnfJp", "RmWjqgA2exxE5r9EE", "eZd3x5rxxxZdo9yKp",
"Y5XSBxxxxYqsWzmGd", "tYByNe4xx9fXKa7BN", "Du94tjwxxT5rXKpay",
"5WybpRaxxzP6b35Ay", "mrcnaaxxxx7EmTRzH", "Fb33axxxxHToRXeba",
"zKQkqSXKrxxxknvsn", "iQ3YLSA7pmxxD63TX", "gpnkGFxxxepJpt6CY",
"GmGDqeSfK7LcxxWux", "6u8cDCtxxxkvQZvPf", "f7Qxxh6t3mqrszC8R",
"y6kMxxxcaa6YmgzqC", "ptHdCvTYcC8xxxmc6", "PmKkemWxxxLY2pRQo" ] } },
limit: 0 } ], ordered: true, lsid: { id:
UUID("da6xxxc1-f311-4b56-xxxx-1d3200d0xxx9") }, $clusterTime: {
clusterTime: Timestamp(1604907002, 34), signature: { hash: BinData(0,
0000000000000000000000000000000000000000), keyId: 0 } }, $db: "parties"
} numYields:0 reslen:214 locks:{ Global: { acquireCount: { r: 37, w: 37
} }, Database: { acquireCount: { w: 37 } }, Collection: { acquireCount:
{ w: 7 } }, o
Nono-m0le commented 3 years ago

Hi @frdmn ,

+3 months after, and several version higher (Snap version 3.10.5) I'm still getting those alerts daily Is there anything I can do at my end to fix that ?

As I'm monitoring the syslog entries, I'm getting alerts several times a day !

Nono-m0le commented 3 years ago

Any update on this issue ?

I'm still getting multiple (false positive) alerts daily

georgschoelly commented 3 years ago

These log messages come from mongodb. It logs slow queries to syslog:

When logLevel is set to 0, MongoDB records slow operations to the diagnostic log at a rate determined by slowOpSampleRate.

For us, this is also a security issue because it can log sensitive data to syslog. I found two ways to fix it:

  1. Set slowOpThresholdMs (or --slowms on the command line) so high it never triggers.
  2. Set --logpath <path> to /dev/null to suppress all diagnostic output. This might also require --logappend.

Unfortunately, I have not found a way to do that in the Snap installation of Rocket.Chat, so consider this a feature request.