Uppy stuck in "Encoding..." state with error [Transloadit] Couldn’t find the file, it was likely removed in the process

[mifi]

Initial checklist

• I understand this is a bug report and questions should be posted in the Community Forum
• I searched issues and couldn’t find anything (or linked relevant results below)

Link to runnable example

No response

Steps to reproduce

yarn dev:with-companion and the Transloadit(tus) plugin,
Use for example DropBox, add a single file and upload it.

Expected behavior

Upload and encoding should succeed.

Actual behavior

This happens about 1 out of 5 times while testing. Upload succeeds but encoding gets stuck and this gets printed:

[Uppy] [12:35:11] Adding files from a remote provider
12:35:11.678 loggers.js:15 [Uppy] [12:35:11] Added file: How to use the Public folder.rtf
 id: id:NBIhAz1dRdQAAAAAAAAABw
 type: application/rtf
12:35:12.052 loggers.js:15 [Uppy] [12:35:12] Adding metadata:
12:35:12.052 loggers.js:15 [Uppy] [12:35:12] {check_test: '1', yo: '1', bla: '12333'}
12:35:12.060 loggers.js:15 [Uppy] [12:35:12] [Transloadit] Create Assembly
12:35:12.081 loggers.js:15 [Uppy] [12:35:12] [Transloadit] Created Assembly 46140cb99b11473a8878b5dcfbd8e0a1
12:35:12.083 loggers.js:15 [Uppy] [12:35:12] [Tus] Uploading...
12:35:14.175 loggers.js:15 [Uppy] [12:35:14] Upload progress: 0.00
12:35:14.195 loggers.js:15 [Uppy] [12:35:14] Closing socket id:NBIhAz1dRdQAAAAAAAAABw
12:35:14.845 loggers.js:15 [Uppy] [12:35:14] [Transloadit] Couldn’t find the file, it was likely removed in the process

I've added logging in #findFile in the transloadit plugin:

    console.log('file.uploadURL', files[0].uploadURL)
    console.log('uploadedFile.tus_upload_url', uploadedFile.tus_upload_url)

and with the logging I see:

[Uppy] [12:35:11] Adding files from a remote provider
12:35:11.678 loggers.js:15 [Uppy] [12:35:11] Added file: How to use the Public folder.rtf
 id: id:NBIhAz1dRdQAAAAAAAAABw
 type: application/rtf
12:35:12.052 loggers.js:15 [Uppy] [12:35:12] Adding metadata:
12:35:12.052 loggers.js:15 [Uppy] [12:35:12] {check_test: '1', yo: '1', bla: '12333'}
12:35:12.060 loggers.js:15 [Uppy] [12:35:12] [Transloadit] Create Assembly
12:35:12.081 loggers.js:15 [Uppy] [12:35:12] [Transloadit] Created Assembly 46140cb99b11473a8878b5dcfbd8e0a1
12:35:12.083 loggers.js:15 [Uppy] [12:35:12] [Tus] Uploading...
12:35:14.175 loggers.js:15 [Uppy] [12:35:14] Upload progress: 0.00
12:35:14.195 loggers.js:15 [Uppy] [12:35:14] Closing socket id:NBIhAz1dRdQAAAAAAAAABw
12:35:14.844 index.js?t=1702009997691:358 file.uploadURL https://api2-singar.transloadit.com/resumable/files/3e6ecb0595b4573e731d4792d658109f
12:35:14.845 index.js?t=1702009997691:359 uploadedFile.tus_upload_url https://api2-sighi.transloadit.com/resumable/files/b96ca0c4629ded60b37520a93a500406
12:35:14.845 loggers.js:15 [Uppy] [12:35:14] [Transloadit] Couldn’t find the file, it was likely removed in the process
12:35:14.845 index.js?t=1702009997691:358 file.uploadURL https://api2-singar.transloadit.com/resumable/files/
12:35:14.845 index.js?t=1702009997691:359 uploadedFile.tus_upload_url https://api2-singar.transloadit.com/resumable/files/3e6ecb0595b4573e731d4792d658109f

Notice that file.uploadURL is different from uploadedFile.tus_upload_url. The domain names are different: singar.transloadit.com vs sighi.transloadit.com and the ID: 3e6ecb0595b4573e731d4792d658109f vs b96ca0c4629ded60b37520a93a500406. I believe this is the culprit, but I don't know how to correctly solve it. Note that this only happens some times when uploading. Most of the time, the URLs are the same.

[Acconut]

That's odd, indeed. I looked at the Assembly status at https://api2.transloadit.com/assemblies/46140cb99b11473a8878b5dcfbd8e0a1 and there are a couple of things to note:

The Assembly is created with one upload to be expected, but two files are uploaded via tus for it. From the logs, it appears as if these two tus uploads were started at basically the same time. One possible explanation is a race condition in companion or tus-js-client, which causes duplicate uploads to be created. The two uploads could also explain why the upload URL changed.

That being said, I am not sure why the tus uploads include size: 0. That's incorrect and I will look into it.

The two files from the tus uploads were also successfully added to the Assembly. Logs from the servers also indicate that jobs for extracting the metadata completed, so the files were properly imported into the api2.

Although the uploads were finished and process by the api2, the assembly is marked as REQUEST_ABORT. I guess this is because bytes_expected !== bytes_received. The formed is calculated based on the size property of the uploads, which are incorrect for some reason.

yarn dev:with-companion and the Transloadit(tus) plugin,
Use for example DropBox, add a single file and upload it.

Do I need some secret credentials in my environment to do this? Can this also be reproduced when using something else than Dropbox?

[mifi]

Ok this is very interesting, thanks!

Do I need some secret credentials in my environment to do this?

yes. but maybe not for the URL plugin.

at least you need inside .env:

VITE_TRANSLOADIT_KEY
VITE_TRANSLOADIT_SERVICE_URL=https://api2.transloadit.com
VITE_TRANSLOADIT_SECRET
VITE_TRANSLOADIT_TEMPLATE
VITE_COMPANION_URL=http://localhost:3020
VITE_UPLOADER=transloadit

see also .env.example (although maybe not quite up to date)

Can this also be reproduced when using something else than Dropbox?

I believe so, and it can be reproduced with the URL plugin. I wanted to ttry to reproduce it on transloadit.com but that is currently broken due to a different issue

[Acconut]

Thanks for the tips! I will wait what you and Merlijn discover. If there is a need for me, I can try to reproduce it as well :)

[mifi]

We found out what's the cause. After a refactor (#4734), Uppy now sends the "resume" event right after starting an upload. This calls this.tus.start():

uppy/packages/@uppy/companion/src/server/Uploader.js

Line 201 in 1b6c260

this.tus.start()

the problem is that this.tus.start() has already been called by companion when the upload started (some hundred milliseconds before). Calling tus.start() twice causes tus-js-client to start the same upload twice, but produce a new uploadUrls the second time, sent back to uppy. I'm not sure if this is intended behaviour in tus-js-client (start the same upload twice in parallel for the same assembly), but we will workaround the issue by implementing a simple state machine to prevent calling tus.start() if we are already in the paused state. for fun we tried to call tus.start() 3 times back-to-back and indeed it uploaded the file 3 times to the assembly.

[Acconut]

Now that you are talking about it, I remember that another user of tus-js-client also ran into duplicate uploads because of the same reason. I opened an issue in tus-js-client to implement protection against this in the future: tus/tus-js-client#659. Thanks for looking it this!