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