Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

fix: Exporting rooms messages as file throws error on server side #29903

Closed
wants to merge 10 commits into from

Conversation

matheusbsilva137
Copy link
Member

@matheusbsilva137 matheusbsilva137 commented Jul 24, 2023

Proposed changes (including videos or screenshots)

  • Create read stream based on file path (and not file descriptor) when uploading zip export file.

Issue(s)

Steps to test or reproduce

Enter a room and access the "Export Messages" option in the menu. Choose the "Export as file" method and pick a date period, then click on the "Export" button.
Currently, an error is thrown (not consistently, it doesn't happen in every attempt):

Error logs
W20231011-13:54:43.044(-3)? (STDERR) (node:140025) Warning: Closing file descriptor 47 on garbage collection
W20231011-13:54:43.045(-3)? (STDERR) (node:140025) [DEP0137] DeprecationWarning: Closing a FileHandle object on garbage collection is deprecated. Please close FileHandle objects explicitly using FileHandle.prototype.close(). In the future, an error will be thrown if a file descriptor is closed during garbage collection.
W20231011-13:54:43.056(-3)? (STDERR) [Error: EBADF: bad file descriptor, read] {
W20231011-13:54:43.056(-3)? (STDERR)   errno: -9,
W20231011-13:54:43.056(-3)? (STDERR)   code: 'EBADF',
W20231011-13:54:43.056(-3)? (STDERR)   syscall: 'read'
W20231011-13:54:43.057(-3)? (STDERR) }
W20231011-13:54:43.059(-3)? (STDERR) === UnHandledPromiseRejection ===
W20231011-13:54:43.060(-3)? (STDERR) Error: EBADF: bad file descriptor, read
W20231011-13:54:43.060(-3)? (STDERR)  => awaited here:
W20231011-13:54:43.060(-3)? (STDERR)     at Function.Promise.await (/home/matheus/.meteor/packages/promise/.0.12.2.bqfx3w.89spp++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/promise_server.js:56:12)
W20231011-13:54:43.060(-3)? (STDERR)     at app/file-upload/server/lib/FileUpload.ts:730:14
W20231011-13:54:43.060(-3)? (STDERR)     at /home/matheus/.meteor/packages/promise/.0.12.2.bqfx3w.89spp++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/fiber_pool.js:43:40
W20231011-13:54:43.060(-3)? (STDERR)  => awaited here:
W20231011-13:54:43.060(-3)? (STDERR)     at Function.Promise.await (/home/matheus/.meteor/packages/promise/.0.12.2.bqfx3w.89spp++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/promise_server.js:56:12)
W20231011-13:54:43.060(-3)? (STDERR)     at server/lib/dataExport/uploadZipFile.ts:37:12
W20231011-13:54:43.060(-3)? (STDERR)     at /home/matheus/.meteor/packages/promise/.0.12.2.bqfx3w.89spp++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/fiber_pool.js:43:40
W20231011-13:54:43.060(-3)? (STDERR)  => awaited here:
W20231011-13:54:43.061(-3)? (STDERR)     at Function.Promise.await (/home/matheus/.meteor/packages/promise/.0.12.2.bqfx3w.89spp++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/promise_server.js:56:12)
W20231011-13:54:43.061(-3)? (STDERR)     at server/lib/dataExport/sendFile.ts:76:12
W20231011-13:54:43.061(-3)? (STDERR)     at /home/matheus/.meteor/packages/promise/.0.12.2.bqfx3w.89spp++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/fiber_pool.js:43:40 {
W20231011-13:54:43.061(-3)? (STDERR)   errno: -9,
W20231011-13:54:43.061(-3)? (STDERR)   code: 'EBADF',
W20231011-13:54:43.061(-3)? (STDERR)   syscall: 'read'
W20231011-13:54:43.061(-3)? (STDERR) }

This error shouldn't be thrown anymore with the changhes in this PR.

Further comments

This error is not consistent to reproduce, but it happens after garbage collection runs (see the warning in the first line of the error logs). What may be going on is that the file descriptor was being closed (since it was unused) before we created the read stream. By using the file path instead we can avoid such errors and skip the open step that doesn't look useful.
TC-851

@matheusbsilva137 matheusbsilva137 requested a review from a team as a code owner July 24, 2023 18:59
@changeset-bot
Copy link

changeset-bot bot commented Jul 24, 2023

🦋 Changeset detected

Latest commit: 991dc0b

The changes in this PR will be included in the next version bump.

This PR includes changesets to release 30 packages
Name Type
@rocket.chat/meteor Patch
@rocket.chat/core-typings Patch
@rocket.chat/rest-typings Patch
@rocket.chat/core-services Patch
@rocket.chat/cron Patch
@rocket.chat/gazzodown Patch
@rocket.chat/livechat Patch
@rocket.chat/model-typings Patch
@rocket.chat/ui-contexts Patch
@rocket.chat/account-service Patch
@rocket.chat/authorization-service Patch
@rocket.chat/ddp-streamer Patch
@rocket.chat/omnichannel-transcript Patch
@rocket.chat/presence-service Patch
@rocket.chat/queue-worker Patch
@rocket.chat/stream-hub-service Patch
@rocket.chat/api-client Patch
@rocket.chat/license Patch
@rocket.chat/omnichannel-services Patch
@rocket.chat/pdf-worker Patch
@rocket.chat/presence Patch
rocketchat-services Patch
@rocket.chat/ddp-client Patch
@rocket.chat/fuselage-ui-kit Patch
@rocket.chat/models Patch
@rocket.chat/ui-client Patch
@rocket.chat/ui-video-conf Patch
@rocket.chat/uikit-playground Patch
@rocket.chat/web-ui-registration Patch
@rocket.chat/instance-status Patch

Not sure what this means? Click here to learn what changesets are.

Click here if you're a maintainer who wants to add another changeset to this PR

KevLehman
KevLehman previously approved these changes Jul 24, 2023
Copy link
Contributor

@KevLehman KevLehman left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't know the context of this so take it as a symbolic approve, but I've been finding this every now and then lol

@codecov
Copy link

codecov bot commented Jul 24, 2023

Codecov Report

Merging #29903 (991dc0b) into develop (c29f5ff) will decrease coverage by 0.15%.
Report is 1 commits behind head on develop.
The diff coverage is n/a.

Impacted file tree graph

@@             Coverage Diff             @@
##           develop   #29903      +/-   ##
===========================================
- Coverage    51.19%   51.04%   -0.15%     
===========================================
  Files          811      809       -2     
  Lines        15059    15158      +99     
  Branches      2750     2812      +62     
===========================================
+ Hits          7709     7738      +29     
- Misses        6940     6983      +43     
- Partials       410      437      +27     
Flag Coverage Δ
e2e 48.37% <ø> (-0.13%) ⬇️
unit 64.04% <ø> (ø)

Flags with carried forward coverage won't be shown. Click here to find out more.

@scuciatto scuciatto added this to the 6.4.0 milestone Jul 25, 2023
Copy link
Member

@debdutdeb debdutdeb left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

without autoclose the fd won't be closed even on an error, please close it manually there too.

i also don't know anything about this, so just a pure technical review

@debdutdeb
Copy link
Member

debdutdeb commented Jul 25, 2023

also, idk the reason seems a bit weird imo. the fd being treated here is a read source, how autoclose works, i don't see how the descriptor could be closed without actually reaching eof. on this path, only if write is reading past eof for some reason or multiple actions are reading from the same file. first is very very unlikely, and if second is the case, this pr won't fix the problem.

or if the source just doesn't exist

maybe im missing something?

@KevLehman
Copy link
Contributor

As a side note, if it's kinda "consitent" to reproduce, you may start to put some logs or debug statements to see what's going on with the descriptor.

Generally you don't need to change the autoClose form for readStreams, which could mean after the stream is being piped is still trying to be used somewhere else, maybe a place without an await or smth.

@scuciatto scuciatto removed this from the 6.4.0 milestone Aug 21, 2023
@matheusbsilva137
Copy link
Member Author

Hey @KevLehman and @debdutdeb guess I've found the real root cause of this issue now
We were getting the file descriptor of the exported zip file and then using it to create a read stream. Apparently, turns out this fd could be closed (by the garbage collector) before we created the actual read stream, which caused that error. This happened frequently on our test envs, but after these changes we couldn't manage to reproduce it anymore.

@dionisio-bot dionisio-bot bot added stat: ready to merge PR tested and approved waiting for merge and removed stat: ready to merge PR tested and approved waiting for merge labels Oct 11, 2023
@dionisio-bot dionisio-bot bot removed the stat: ready to merge PR tested and approved waiting for merge label Oct 11, 2023
@dionisio-bot dionisio-bot bot added the stat: ready to merge PR tested and approved waiting for merge label Oct 11, 2023
@dionisio-bot dionisio-bot bot added stat: ready to merge PR tested and approved waiting for merge and removed stat: ready to merge PR tested and approved waiting for merge labels Oct 20, 2023
@kodiakhq kodiakhq bot removed the stat: ready to merge PR tested and approved waiting for merge label Oct 20, 2023
@kodiakhq
Copy link
Contributor

kodiakhq bot commented Oct 20, 2023

This PR currently has a merge conflict. Please resolve this and then re-add the ['stat: ready to merge', 'automerge'] label.

@sampaiodiego
Copy link
Member

closed by #30657

unfortunately I was not actually aware of this PR and fixed the same thing in the above PR.. 😬

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

6 participants