Slow/stuck resync on S3 storage

I created a couple of files straight on a swift storage and run a resync. It takes age (dozens of minutes).
Here are the logs ¹ for this storage (pydio.grpc.data.sync.ovhc) between 15:02 and 15:24.
Directory create using Swift were not available as workspaces roots before long (only a couple of directories were available after 20 minutes).
[It’s an OVH-hosted PCA Swift object-storage using the s3 middleware]

15:02:28Z	info	Got Stats for index://ovhc				
15:03:49Z	info	Create Hidden File for folder				(.pydio)
15:03:50Z	info	Got Stats for s3://IP:9001/cpydio				
15:03:50Z	info	Listing all S3 objects for path				()
15:03:50Z	info	Create Hidden File for folder				(DE/.pydio)
15:03:52Z	info	Create Hidden File for folder				(ES/.pydio)
15:03:52Z	info	Create Hidden File for folder				(IN/.pydio)
15:03:53Z	info	Create Hidden File for folder				(INT/.pydio)
15:03:54Z	info	Create Hidden File for folder				(IT/.pydio)
15:03:54Z	info	Create Hidden File for folder				(FR/.pydio)
15:03:55Z	info	Create Hidden File for folder				(XX/.pydio)
15:03:56Z	info	Create Hidden File for folder				(XY/.pydio)
15:04:52Z	info	Create Hidden File for folder				(IN/.pydio)
15:05:15Z	info	Create Hidden File for folder				(ES/.pydio)
15:05:18Z	info	Create Hidden File for folder				(XX/.pydio)
15:05:20Z	info	Create Hidden File for folder				(INT/.pydio)
15:05:22Z	info	Create Hidden File for folder				(FR/.pydio)
15:05:26Z	info	Create Hidden File for folder				(DE/.pydio)
15:05:36Z	info	Create Hidden File for folder				(IT/.pydio)
15:05:37Z	info	Create Hidden File for folder				(XY/.pydio)
15:05:38Z	info	S3 Walk Operation + Stats took	108.185855398			
15:05:38Z	info	Diff Stats				
15:05:38Z	info	Finished analyzing nodes				
15:05:38Z	info	Sending unidirectional patch			{"Source":"s3://IP:9001/cpydio","Target":"index://ovhc","Type":"TreePatch"}	
15:05:38Z	info	Filtering TreePatch took				
15:05:38Z	info	Created folder				(DE)
15:05:38Z	info	Created folder				(ES)
15:05:38Z	info	Created folder				(IN)
15:05:38Z	info	Created folder				(INT)
15:05:38Z	info	Created folder				(IT)
15:05:38Z	info	Created folder				(FR)
15:05:38Z	info	Created folder				(XX)
15:05:38Z	info	Created folder				(XY)
15:05:38Z	info	Indexed file				(DE/.pydio)
15:05:38Z	info	Indexed file				(DE/README.txt)
15:05:39Z	info	Indexed file				(ES/.pydio)
15:05:39Z	error	Error while indexing file		500	Error while inserting node: Cache:GetNodeByPath: Path: [ES] last part not in nameCache		(ES/README.txt)
15:05:39Z	info	Indexed file				(IN/.pydio)
15:05:39Z	info	Indexed file				(IN/README.txt)
15:05:39Z	error	Error while indexing file		500	Error while inserting node: Cache:GetNodeByPath: Path: [INT] last part not in nameCache		(INT/.pydio)
15:05:39Z	error	Error while indexing file		500	Error while inserting node: Cache:GetNodeByPath: Path: [INT] last part not in nameCache		(INT/README.txt)
15:05:39Z	error	Error while indexing file		500	Error while inserting node: Cache:GetNodeByPath: Path: [IT] last part not in nameCache		(IT/.pydio)
15:05:39Z	info	Indexed file				(IT/README.txt)
15:05:39Z	error	Error while indexing file		500	Error while inserting node: Cache:GetNodeByPath: Path: [FR] last part not in nameCache		(FR/.pydio)
15:05:39Z	info	Indexed file				(FR/README.txt)
15:05:39Z	info	Indexed file				(XX/.pydio)
15:05:39Z	error	Error while indexing file		500	Error while inserting node: Cache:GetNodeByPath: Path: [XX] last part not in nameCache		(XX/README.txt)
15:05:40Z	error	Error while indexing file		500	Error while inserting node: Cache:GetNodeByPath: Path: [XY] last part not in nameCache		(XY/.pydio)
15:05:40Z	error	Error while indexing file		500	Error while inserting node: Cache:GetNodeByPath: Path: [XY] last part not in nameCache		(XY/README.txt)
15:05:40Z	error	Patch ended with errors				
15:05:40Z	error	--- Error		500	Error while inserting node: Cache:GetNodeByPath: Path: [XY] last part not in nameCache		
15:05:40Z	error	--- Error		500	Error while inserting node: Cache:GetNodeByPath: Path: [ES] last part not in nameCache		
15:05:40Z	error	--- Error		500	Error while inserting node: Cache:GetNodeByPath: Path: [INT] last part not in nameCache		
15:05:40Z	error	--- Error		500	Error while inserting node: Cache:GetNodeByPath: Path: [INT] last part not in nameCache		
15:05:40Z	error	--- Error		500	Error while inserting node: Cache:GetNodeByPath: Path: [IT] last part not in nameCache		
15:05:40Z	error	--- Error		500	Error while inserting node: Cache:GetNodeByPath: Path: [FR] last part not in nameCache		
15:05:40Z	error	--- Error		500	Error while inserting node: Cache:GetNodeByPath: Path: [XX] last part not in nameCache		
15:05:40Z	error	--- Error		500	Error while inserting node: Cache:GetNodeByPath: Path: [XY] last part not in nameCache		
15:05:40Z	error	--- Error		500	Error while inserting node: Cache:GetNodeByPath: Path: [XY] last part not in nameCache		
15:07:26Z	info	Got Stats for index://ovhc				
15:08:55Z	info	Create Hidden File for folder				(.pydio)
15:08:57Z	info	Got Stats for s3://IP:9001/cpydio				
15:08:57Z	info	Listing all S3 objects for path				()
15:10:24Z	info	Create Hidden File for folder				(DE/.pydio)
15:12:26Z	info	Create Hidden File for folder				(ES/.pydio)
15:14:04Z	info	Create Hidden File for folder				(IN/.pydio)
15:15:15Z	info	Create Hidden File for folder				(INT/.pydio)
15:17:10Z	info	Create Hidden File for folder				(IT/.pydio)
15:18:57Z	info	Create Hidden File for folder				(FR/.pydio)
15:20:43Z	info	Create Hidden File for folder				(XX/.pydio)
15:22:23Z	info	Create Hidden File for folder				(XY/.pydio)
15:23:32Z	info	Create Hidden File for folder				(INT/.pydio)
15:23:41Z	info	Create Hidden File for folder				(FR/.pydio)
15:23:42Z	info	Create Hidden File for folder				(XY/.pydio)
15:23:46Z	info	Create Hidden File for folder				(IN/.pydio)
15:23:53Z	info	Create Hidden File for folder				(DE/.pydio)
15:23:53Z	info	Create Hidden File for folder				(IT/.pydio)
15:24:08Z	info	Create Hidden File for folder				(XX/.pydio)
15:24:09Z	info	Create Hidden File for folder				(ES/.pydio)
15:24:10Z	info	S3 Walk Operation + Stats took	913.203452938			
15:24:10Z	info	Diff Stats				
15:24:10Z	info	Finished analyzing nodes				
15:24:10Z	info	Sending unidirectional patch			{"Source":"s3://IP:9001/cpydio","Target":"index://ovhc","Type":"TreePatch"}	
15:24:10Z	info	Filtering TreePatch took				
15:24:10Z	info	Created folder				(DE)
15:24:10Z	info	Created folder				(ES)
15:24:10Z	info	Created folder				(IN)
15:24:10Z	info	Created folder				(INT)
15:24:10Z	info	Created folder				(IT)
15:24:10Z	info	Created folder				(FR)
15:24:10Z	info	Created folder				(XX)
15:24:10Z	info	Created folder				(XY)
15:24:10Z	error	Error while indexing file		500	Error while inserting node: Cache:GetNodeByPath: Path: [DE] last part not in nameCache		(DE/.pydio)
15:24:10Z	info	Indexed file				(DE/README.txt)
15:24:10Z	info	Indexed file				(ES/.pydio)
15:24:10Z	error	Error while indexing file		500	Error while inserting node: Cache:GetNodeByPath: Path: [ES] last part not in nameCache		(ES/README.txt)
15:24:10Z	error	Error while indexing file		500	Error while inserting node: Cache:GetNodeByPath: Path: [IN] last part not in nameCache		(IN/.pydio)
15:24:10Z	error	Error while indexing file		500	Error while inserting node: Cache:GetNodeByPath: Path: [IN] last part not in nameCache		(IN/README.txt)
15:24:10Z	error	Error while indexing file		500	Error while inserting node: Cache:GetNodeByPath: Path: [INT] last part not in nameCache		(INT/.pydio)
15:24:10Z	info	Indexed file				(INT/README.txt)
15:24:11Z	info	Indexed file				(IT/.pydio)
15:24:11Z	error	Error while indexing file		500	Error while inserting node: Cache:GetNodeByPath: Path: [IT] last part not in nameCache		(IT/README.txt)
15:24:11Z	info	Indexed file				(FR/.pydio)
15:24:11Z	error	Error while indexing file		500	Error while inserting node: Cache:GetNodeByPath: Path: [FR] last part not in nameCache		(FR/README.txt)
15:24:11Z	info	Indexed file				(XX/.pydio)
15:24:11Z	info	Indexed file				(XX/README.txt)
15:24:11Z	error	Error while indexing file		500	Error while inserting node: Cache:GetNodeByPath: Path: [XY] last part not in nameCache		(XY/.pydio)
15:24:11Z	error	Error while indexing file		500	Error while inserting node: Cache:GetNodeByPath: Path: [XY] last part not in nameCache		(XY/README.txt)
15:24:11Z	error	Patch ended with errors				
15:24:11Z	error	--- Error		500	Error while inserting node: Cache:GetNodeByPath: Path: [XY] last part not in nameCache		
15:24:11Z	error	--- Error		500	Error while inserting node: Cache:GetNodeByPath: Path: [DE] last part not in nameCache		
15:24:11Z	error	--- Error		500	Error while inserting node: Cache:GetNodeByPath: Path: [ES] last part not in nameCache		
15:24:11Z	error	--- Error		500	Error while inserting node: Cache:GetNodeByPath: Path: [IN] last part not in nameCache		
15:24:11Z	error	--- Error		500	Error while inserting node: Cache:GetNodeByPath: Path: [IN] last part not in nameCache		
15:24:11Z	error	--- Error		500	Error while inserting node: Cache:GetNodeByPath: Path: [INT] last part not in nameCache		
15:24:11Z	error	--- Error		500	Error while inserting node: Cache:GetNodeByPath: Path: [IT] last part not in nameCache		
15:24:11Z	error	--- Error		500	Error while inserting node: Cache:GetNodeByPath: Path: [FR] last part not in nameCache		
15:24:11Z	error	--- Error		500	Error while inserting node: Cache:GetNodeByPath: Path: [XY] last part not in nameCache		
15:24:11Z	error	--- Error		500	Error while inserting node: Cache:GetNodeByPath: Path: [XY] last part not in nameCache

I found that doing:
swift download cpydio XX/.pydio
I would get Error downloading object 'cpydio/XX/.pydio': Object GET failed: https://storage.de.cloud.ovh.net/v1/_____/cpydio/XX/.pydio 429 Too Many Requests

I later tcpdump'ed the traffic with storage.de.cloud.ovh.net but it seemed mostly normal (although I may have missed possible previous bursts).

My guess is that Pydio is sending burst of requests (for some reason), which reiteratly overcome the quota what implies that some succesful Swift request happens once the quota is reset (every minute?) but this quota is immediatly exceeded again.

As commented previously, I strongly lack a traffic analysis tool (= extended traffic log).
Using tcpdump to somehow monitor (HTTPS) requests to a storage backend is too rudimentary to successfully debug/explore (and resolve) this class of problems.

¹ jq -rs '.[] | [.ts, .level, .msg, .d, (if .error then .error|fromjson | [.code, .detail] else "" end), (if .patch then .patch|tojson else "" end), (if (.NodePath // .path) then "(" + (.NodePath // .path) + ")" else "" end)] | flatten | @tsv' /tmp/log.json

Hi @drzraf just to know, were you using 2.0.9 or the master ( = 2.1) ? In the first case, can you try again with 2.1 ?

It’s on 2.1
I’ll soon try again using a PCS storage instead of PCA (public cloud archive) to see if the quota problems comes mainly came from that specific storage backend or from Pydio requests.