RocketChat / Rocket.Chat

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

cronProcessDownloads.js fails every 120s (related to #17714) #18647

Closed glunardi closed 4 years ago

glunardi commented 4 years ago

Description:

cron job fails every 120s. Looks related to #17714

Server started (installed vanilla with 3.4.2). Could there be something missing in #17577? Something else helped suppress the issue?

Again 3.4.2 is the only version to ever run on our install.

Steps to reproduce:

Unclear but from #17577 : Have 2 users and create a DM and send some message between them in your environment; As admin user, go to "Administration" > "User Data Download" and make sure this option is enabled; As any of the users, go to "My Account" > "Preferences" and click at "Export My Data" or "Download My Data" located at the bottom of that page; When the cron runs it will fail with "TypeError: Cannot read property 'filter' of undefined" because roomId is a string and has no uids in it;

Expected behavior:

Scheduled tasks should gracefully handle exceptions

Actual behavior:

Aug 22 10:42:00 chat rocketchat[1132]: === UnHandledPromiseRejection ===
Aug 22 10:42:00 chat rocketchat[1132]: TypeError: Cannot read property 'filter' of undefined
Aug 22 10:42:00 chat rocketchat[1132]:     at app/user-data-download/server/cronProcessDownloads.js:51:59
Aug 22 10:42:00 chat rocketchat[1132]:     at SynchronousCursor.forEach (packages/mongo/mongo_driver.js:1138:16)
Aug 22 10:42:00 chat rocketchat[1132]:     at Cursor.<computed> [as forEach] (packages/mongo/mongo_driver.js:918:44)
Aug 22 10:42:00 chat rocketchat[1132]:     at loadUserSubscriptions (app/user-data-download/server/cronProcessDownloads.js:47:9)
Aug 22 10:42:00 chat rocketchat[1132]:     at app/user-data-download/server/cronProcessDownloads.js:499:3
Aug 22 10:42:00 chat rocketchat[1132]:     at /opt/Rocket.Chat/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/fiber_pool.js:43:40
Aug 22 10:42:00 chat rocketchat[1132]:  => awaited here:
Aug 22 10:42:00 chat rocketchat[1132]:     at Function.Promise.await (/opt/Rocket.Chat/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/promise_server.js:56:12)
Aug 22 10:42:00 chat rocketchat[1132]:     at app/user-data-download/server/cronProcessDownloads.js:577:2
Aug 22 10:42:00 chat rocketchat[1132]:     at /opt/Rocket.Chat/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/fiber_pool.js:43:40
Aug 22 10:42:00 chat rocketchat[1132]: ---------------------------------
Aug 22 10:42:00 chat rocketchat[1132]: Errors like this can cause oplog processing errors.
Aug 22 10:42:00 chat rocketchat[1132]: Setting EXIT_UNHANDLEDPROMISEREJECTION will cause the process to exit allowing your service to automatically restart the process
Aug 22 10:42:00 chat rocketchat[1132]: Future node.js versions will automatically exit the process
Aug 22 10:42:00 chat rocketchat[1132]: =================================

Server Setup Information:

Rocket.Chat
Version 3.4.2
Apps Engine Version 1.15.0
Database Migration  197
Database Migration Date August 22, 2020 0:12
Installed at    July 27, 2020 18:35
Uptime  9 hours, 59 minutes, 38 seconds
Deployment ID   <removed-from-issue-ticket-just-in-case>
PID 1132
Running Instances   1
OpLog   Enabled
Commit
Hash    e5f93d3f5e31172404622c06ebec5b5c9f24143d
Date    Fri Jul 10 18:07:11 2020 -0300
Branch  HEAD
Tag 3.4.2
Author  Rodrigo Nascimento
Subject Merge pull request #18241 from RocketChat/release-3.4.2
Runtime Environment
OS Type Linux
OS Platform linux
OS Arch x64
OS Release  5.4.0-42-generic
Node Version    v12.14.0
Mongo Version   4.0.19
Mongo Storage Engine    mmapv1
OS Uptime   10 hours, 2 minutes, 41 seconds
OS Load Average 0.02, 0.01, 0.00
OS Total Memory 15.64 GB
OS Free Memory  13.95 GB
OS CPU Count    8
Build Environment
OS Platform linux
OS Arch x64
OS Release  5.3.0-1031-azure
Node Version    v12.16.1
Date    July 10, 2020 17:14
Usage
Total Users 374
Activated Users 374
Activated Guests    0
Rocket.Chat App Users   0
Deactivated Users   0
Total Connected Users   30
Online Users    6
Away Users  24
Offline Users   344
Total Rooms 71
Total Channels  32
Total Private Groups    4
Total Direct Message Rooms  35
Total Omnichannel Rooms 0
Total Discussions   2
Total Threads   97
Total Messages  49445
Total Messages in Channels  1246
Total Messages in Private Groups    1462
Total Messages in Direct Messages   46737
Total Messages in Omnichannel   0
Total Uploads   13
Total Uploads Size  6.59 MB
Total Installed Apps    0
Total Active Apps   0
Total Integrations  0
Total Incoming Integrations 0
Total Active Incoming Integrations  0
Total Outgoing Integrations 0
Total Active Outgoing Integrations  0
Total Integrations With Script Enabled  0

Client Setup Information

does not matter

Additional context

Looked at the app.js really quick and ccb00d46fc71de1873a0d4d3f877005aff6a8bcc is applied:

const loadUserSubscriptions = function (exportOperation) {
  exportOperation.roomList = [];
  const exportUserId = exportOperation.userId;
  const cursor = Subscriptions.findByUserId(exportUserId);
  cursor.forEach(subscription => {
    const roomId = subscription.rid;
    const roomData = Rooms.findOneById(roomId);
    const roomName = roomData && roomData.name && subscription.t !== 'd' ? roomData.name : roomId;
    const [userId] = subscription.t === 'd' ? roomData.uids.filter(uid => uid !== exportUserId) : [null];
    const fileName = exportOperation.fullExport ? roomId : roomName;
    const fileType = exportOperation.fullExport ? 'json' : 'html';
    const targetFile = "".concat(fileName, ".").concat(fileType);
    exportOperation.roomList.push({
      roomId,
      roomName,
      userId,
      exportedCount: 0,
      status: 'pending',
      targetFile,
      type: subscription.t
    });
  });

Relevant logs:

Aug 22 10:42:00 chat rocketchat[1132]: === UnHandledPromiseRejection ===
Aug 22 10:42:00 chat rocketchat[1132]: TypeError: Cannot read property 'filter' of undefined
Aug 22 10:42:00 chat rocketchat[1132]:     at app/user-data-download/server/cronProcessDownloads.js:51:59
Aug 22 10:42:00 chat rocketchat[1132]:     at SynchronousCursor.forEach (packages/mongo/mongo_driver.js:1138:16)
Aug 22 10:42:00 chat rocketchat[1132]:     at Cursor.<computed> [as forEach] (packages/mongo/mongo_driver.js:918:44)
Aug 22 10:42:00 chat rocketchat[1132]:     at loadUserSubscriptions (app/user-data-download/server/cronProcessDownloads.js:47:9)
Aug 22 10:42:00 chat rocketchat[1132]:     at app/user-data-download/server/cronProcessDownloads.js:499:3
Aug 22 10:42:00 chat rocketchat[1132]:     at /opt/Rocket.Chat/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/fiber_pool.js:43:40
Aug 22 10:42:00 chat rocketchat[1132]:  => awaited here:
Aug 22 10:42:00 chat rocketchat[1132]:     at Function.Promise.await (/opt/Rocket.Chat/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/promise_server.js:56:12)
Aug 22 10:42:00 chat rocketchat[1132]:     at app/user-data-download/server/cronProcessDownloads.js:577:2
Aug 22 10:42:00 chat rocketchat[1132]:     at /opt/Rocket.Chat/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/fiber_pool.js:43:40
Aug 22 10:42:00 chat rocketchat[1132]: ---------------------------------
Aug 22 10:42:00 chat rocketchat[1132]: Errors like this can cause oplog processing errors.
Aug 22 10:42:00 chat rocketchat[1132]: Setting EXIT_UNHANDLEDPROMISEREJECTION will cause the process to exit allowing your service to automatically restart the process
Aug 22 10:42:00 chat rocketchat[1132]: Future node.js versions will automatically exit the process
Aug 22 10:42:00 chat rocketchat[1132]: =================================
close-issue-app[bot] commented 4 years ago

This issue was closed because it does not use our bug report issue template.

Please make sure to use it and fill it as much as you can so we can provide better and faster support.

The following sections must not be removed, or else the BOT will close it immediately again: