Cells-sync 0.9.2 doesn't trigger multipart uploads proprerly with a Cells v4 server and fails at 5GB using an S3 backend

[jqueuniet]

I'm running into troubles using big files with an S3-compatible storage backend, namely Wasabi. My uploads get discarded with the following error message if they weight more than 5GB:

[ERROR] Cannot PutObject Your proposed upload size ‘11180389380’ exceeds the maximum allowed object size ‘5368709120’ for single PUT operation.

Reading the Wasabi doc, 5GB seems to be the threshold where their S3 API is expecting multipart uploads rather than single PUT operations: https://wasabi-support.zendesk.com/hc/en-us/articles/115001684511-What-are-the-minimum-and-maximum-object-sizes-that-can-be-stored-in-Wasabi- (they actually recommend multipart starting at 100MB file sizes).

I'm currently using Pydio Cells 4.0.0-rc5, in a Kubernetes setup described more in-depth here: https://forum.pydio.com/t/broken-setup-in-kubernetes-500-502-ws-xhr-errors/4691

[jqueuniet]

Reading the Amazon S3 FAQ, this doesn't seem to be specific to Wasabi, but the expected behavior of an S3-compatible API.

https://aws.amazon.com/s3/faqs/

[cdujeu]

Hi @jqueuniet are you uploading the file through the web interface? It should use multipart by default, did you change any values in the upload options?

[jqueuniet]

I uploaded using the desktop client cells-sync, tried with both the Linux and Windows ones. I haven't tried web uploads, as they seemed to be discouraged for heavy uploads.

The server is configured for multipart between the client and the server. Multipart threshold is at 100MB, and the part size at 50MB.

This specific error message seems to originate from the S3 backend though, not the Pydio Cells server, as Pydio didn't have any upper limit configured for file size and the 5GB limit seems to be an S3 API one.

[jqueuniet]

I'm also getting this error message repeatedly during uploads in the server logs, not sure if this is important or not.

GroupPath : /
HttpProtocol : HTTP/1.1
JsonZaps : {"ContentType":"application/octet-stream"}
Level : warn
Logger : pydio.gateway.data
Msg : views.handler.encryption.MultiPartCreate: Missing special header to store clear size when uploading on encrypted data source - Setting ClearSize as unknown
RemoteAddress : 100.64.137.64
Ts : 1664736097
UserAgent : cells-sync/0.9.2
UserName : <username>
UserUuid : a669180c-f47b-497a-a65d-9183047ce4b1
SpanUuid : span-89

[jqueuniet]

By the way, I had an open question related to big file uploads, namely where the chunks uploaded by the client to the Pydio server are temporarily stored before being sent, if they are stored at all and not immediately forwarded as S3 multipart chunks to the S3 backend.

Currently, I allocated a 10GB Kubernetes PV for the Pydio working directory /var/cells, and it could be an issue if chunks do pile up there before being sent, as in practice my volume size would be more or less the max file size I can upload. If they get stored somewhere else out of this directory, like /tmp, then it's not as much of an issue for me as my host filesystem is much larger (150GB) but I would rather know exactly where in order to formalize it in the manifest with an emptydir volume rather than let GB of files pile up in the root overlayfs of the container.

[cdujeu]

Hello,
Multiple points here...
1 - 5GB with cells-sync : have to recheck, but maybe cells-sync does not properly swtich to multipart with v4.
2 - Error logs : not sure
3 - /tmp folder : if you are pointing to an s3 compatible storage that supports multipart, minio acts as a gateway and should forward parts directly, so there is no heavy usage of the minio /tmp folder normally.
4 - K8s : we are finalizing k8s integration of the v4, soon we will publish guidelines for that.

[jqueuniet]

Thanks for the pointers. I tried doing an upload using the web interface and it did work as intended, so cells-sync is the most likely culprit. I'm using cells-sync release version 0.9.2, as the log above showed.

Trying again using the Windows client, I get the following logs client-side about halfway though the upload, when the 5GB threshold is reached:

2022-10-03T20:27:25.634+0200	ERROR	sync-task	Error while transferring file	{"NodePath": "13.2.tar.xz", "target": "https://pydio-cells.domain.example/personal-files/test"}
2022-10-03T20:27:25.634+0200	ERROR	sync-task	Status: Error while transferring file (io: read/write on closed pipe) - retrying...
"NodePath": "13.2.tar.xz", "target": "https://pydio-cells.domain.example/personal-files/test", "error": "context canceled", "target": "https://pydio-cells.domain.example/personal-files/test"}
2022-10-03T20:27:42.833+0200	ERROR	sync-task	Error while transferring file	{"NodePath": "13.2.tar.xz", "target": "https://pydio-cells.domain.example/personal-files/test", "error": "context canceled"}

Server-side, this is the application log at abort time:

GroupPath : /
HttpProtocol : HTTP/1.1
Level : error
Logger : pydio.gateway.data
Msg : PutObjectPart has failed - Put "https://s3.eu-central-2.wasabisys.com/<bucket>-personnal/b740fe56-020a-49bc-8bf2-2b6c7cc5994c?partNumber=3&uploadId=Y0LpxQPunEy8z5tvni9dHCvs_7fHFzVMk4aXJgoypeo_kRmLd9jFHTMcCXTmwmMGcoAjLB2fIDWtTZfUDqVemyZl2fkmCAuHjxhOJLQ2P28_Xskkhc2-s9i3g4dJ2Ogz": context canceled
RemoteAddress : 49.12.212.170
Ts : 1664821662
UserAgent : cells-sync/0.9.2
UserName : <username>
UserUuid : a669180c-f47b-497a-a65d-9183047ce4b1
SpanUuid : span-6

GroupPath : /
HttpProtocol : HTTP/1.1
Level : error
Logger : pydio.gateway.data
Msg : views.handler.encryption.MultiPartPutObject: Next handler failed - Put "https://s3.eu-central-2.wasabisys.com/<bucket>-personal/b740fe56-020a-49bc-8bf2-2b6c7cc5994c?partNumber=3&uploadId=Y0LpxQPunEy8z5tvni9dHCvs_7fHFzVMk4aXJgoypeo_kRmLd9jFHTMcCXTmwmMGcoAjLB2fIDWtTZfUDqVemyZl2fkmCAuHjxhOJLQ2P28_Xskkhc2-s9i3g4dJ2Ogz": context canceled
RemoteAddress : 49.12.212.170
Ts : 1664821662
UserAgent : cells-sync/0.9.2
UserName : <username>
UserUuid : a669180c-f47b-497a-a65d-9183047ce4b1
SpanUuid : span-5

Level : error
Logger : pydio.grpc.data-key
Msg : data.key.handler.SetNodeInfo: failed to read SetInfoRequest - rpc error: code = Canceled desc = context canceled
SpanParentUuid : 6a93ee99-22d9-4427-ae2c-eece8895bf8a
SpanRootUuid : 6a93ee99-22d9-4427-ae2c-eece8895bf8a
SpanUuid : 7de06a0f-03fe-4f61-8b42-b7311985a5f6
Ts : 1664821662
HasRoot : true

Level : error
Logger : pydio.grpc.data-key
Msg : data.key.handler.SetNodeInfo: failed to read SetInfoRequest - rpc error: code = Canceled desc = context canceled
SpanParentUuid : 6a93ee99-22d9-4427-ae2c-eece8895bf8a
SpanRootUuid : 6a93ee99-22d9-4427-ae2c-eece8895bf8a
SpanUuid : 6a93ee99-22d9-4427-ae2c-eece8895bf8a
Ts : 1664821662
HasChildren : true
IsOpen : true

The error mentioned in my first message only appears in the container output, not in the application logs as recorded in the web UI.

[cdujeu]

Hi Johann can you try with the last dev builds of cells-sync ? See https://download.pydio.com/pub/cells-sync/dev/

[jqueuniet]

Hi,

Using this new build, the upload goes farther on Windows, about 3/4 of the way but still gets cancelled before the end. The cells sync logs look like this:

2022-10-07T20:03:27.687+0200	INFO	sync-task	Merged Patch	{"stats": {"Pending":{"CreateFile":1,"Total":1},"Source":"https://pydio-cells.domain.example/personal-files/test","Target":"fs:///C:/Users/Johann/Cells","Type":"TreePatch"}}
2022-10-07T20:03:34.384+0200	INFO	oidc	Additional safe check for token https://johann@pydio-cells.domain.example
2022-10-07T20:05:34.381+0200	INFO	oidc	Additional safe check for token https://johann@pydio-cells.domain.example
2022-10-07T20:07:34.386+0200	INFO	oidc	Additional safe check for token https://johann@pydio-cells.domain.example
2022-10-07T20:09:34.383+0200	INFO	oidc	Additional safe check for token https://johann@pydio-cells.domain.example
2022-10-07T20:11:24.000+0200	INFO	oidc	Refreshing token for https://pydio-cells.domain.example
2022-10-07T20:11:24.154+0200	INFO	oidc	Got new token, will expire in 599
2022-10-07T20:11:27.884+0200	ERROR	sync-task	Error while transferring file	{"NodePath": "13.2.tar.xz", "target": "https://pydio-cells.domain.example/personal-files/test"}
2022-10-07T20:11:27.884+0200	ERROR	sync-task	Status: Error while transferring file (io: read/write on closed pipe) - retrying...
2022-10-07T20:11:34.390+0200	INFO	oidc	Additional safe check for token https://johann@pydio-cells.domain.example
2022-10-07T20:12:04.755+0200	ERROR	endpoint.cells.remote	Stopping watcher on errorrpc error: code = DeadlineExceeded desc = context deadline exceeded
2022-10-07T20:12:04.755+0200	INFO	sync-task	https://pydio-cells.domain.example/personal-files/test is currently disconnected
2022-10-07T20:12:09.761+0200	INFO	endpoint.cells.remote	Restarting events watcher after 5s
2022-10-07T20:12:09.761+0200	INFO	sync-task	https://pydio-cells.domain.example/personal-files/test is now connected

On the server side, the only related log left is a warning related to encryption when the upload starts:

GroupPath : /
HttpProtocol : HTTP/1.1
JsonZaps : {"ContentType":"application/octet-stream"}
Level : warn
Logger : pydio.gateway.data
Msg : views.handler.encryption.MultiPartCreate: Missing special header to store clear size when uploading on encrypted data source - Setting ClearSize as unknown
RemoteAddress : 100.64.137.64
Ts : 1665166293
UserAgent : cells-sync/0.9.3-dev.202210051504
UserName : johann
UserUuid : a669180c-f47b-497a-a65d-9183047ce4b1
SpanUuid : span-1

I'll try later with the Linux client and take a look at the container logs, can't do that from Windows.

[jqueuniet]

Getting the same behaviour with the Linux client, container logs didn't have anything of interest aside from the fact log lines with 200 chunks are long enough to make k9s choke when text is unwrapped.

Since encryption was mentioned, I tried turning it off on the personal bucket, then all of them, but nothing changed.

[cdujeu]

hi again, did you retry all that with the recent v4 ?
question, do you have some kind of proxy (ingress ?) in front of the server? Nginx can have limiting defaults for request body, see for example https://forum.pydio.com/t/403-and-502-errors-when-uploading-large-files-especially-1-gb/4709/8 ?

[jqueuniet]

Hello, tried again this morning using cells v4.0.1 and the latest cells-sync dev snapshot, still the same issue. I can now see the S3 error in the cells-sync logs though.

[ERROR] Cannot PutObject Your proposed upload size ‘11180389380’ exceeds the maximum allowed object size ‘5368709120’ for single PUT operation.
2022-10-20T08:39:26.006+0200	ERROR	sync-task	Error while transferring file	{"NodePath": "13.2.tar.xz", "target": "https://pydio-cells.domain.example/personal-files/test"}
2022-10-20T08:39:26.006+0200	ERROR	sync-task	Status: Error while transferring file (io: read/write on closed pipe) - retrying...

I'm using Traefik as ingress controller, not aware of any significant file size or timeout restrictions.

[cdujeu]

damn, that one shows that you (?) downgraded the cells-sync version as it does not switch to multipart

[jqueuniet]

My cells-sync version is one of the latest dev snapshot.

❯ cells-sync version

    Cells Sync Client (0.9.3-dev.202210191531)
    Published on 19 Oct 22 15:39 +0000
    Revision number fe1fdd61e5d1856a0a2e781ff1bc295bcd501822

[jqueuniet]

I also get this error in cell-sync, but only when WebView was successfully forked in its own window.

2022-10-20T23:49:14.007+0200	ERROR	systray	http://localhost:3636/static/js/main.23910831.chunk.js?__WB_REVISION__=2ead0aadea3ea7924fb1:1:142766: CONSOLE LOG [object Object]

When the fork fails and the web UI is loaded in the web browser instead, I don't get any message like this, The upload fails in both cases.