search

owncloud / ocis

:atom_symbol: ownCloud Infinite Scale Stack
https://doc.owncloud.com/ocis/next/
Apache License 2.0
1.4k stars 182 forks source link

500 error response on conflict for tus upload #8804

Closed dkocher closed 1 month ago

dkocher commented 6 months ago

Describe the bug

A PATCH request for the last part of a resumable file upload fails with a 500 status code on a conflict with another file uploaded with the same target location in the meantime. 

HTTP/1.1 500 Internal Server Error
Content-Length: 0
Content-Type: text/plain; charset=utf-8
Date: Sat, 06 Apr 2024 19:48:28 GMT
Oc-Fileid: dc45dd6e-bcda-4cf7-817d-9e5910d04ac8$da23878d-09a7-4172-8782-9a0faed7bc8a!d9d8eb90-fdc6-4b31-b6dd-957b9a93b907
Tus-Resumable: 1.0.0
Upload-Expires: 1712519272
Upload-Offset: 107174079
Vary: Origin
X-Content-Type-Options: nosniff
X-Request-Id: 71224ad1e77b/lWWOwZAZNP-011923

Expected behavior

I would expecte the upload to fail with 409 Conflict.

micbar commented 6 months ago

@butonic @kobergj

should be a quick fix

butonic commented 6 months ago

@dkocher Did you send any HTTP Preconditions with the initial POST request?

dkocher commented 6 months ago

@dkocher Did you send any HTTP Preconditions with the initial POST request?

There are no preconditions like If-Match header set. The initial request to start a conflicting upload looks like 

POST /remote.php/webdav HTTP/1.1
Tus-Resumable: 1.0.0
Upload-Length: 163157058
Upload-Metadata: filename TW91bnRhaW4gRHVjay00LjE1LjcuMjIwNDcuemlw, mtime 1712677748, filetype application/zip,
Content-Length: 0
Host: ocis.ocis-keycloak.latest.owncloud.works
Connection: Keep-Alive
User-Agent: Cyberduck/8.8.3.41353 (Mac OS X/14.4.1) (aarch64)
Accept-Encoding: gzip,deflate
Authorization: Bearer ***
micbar commented 4 months ago

@dkocher @butonic Please figure that out.

From the original problem description, it is hard for me to understand the request flow needed to trigger that.

@dkocher Can you provide more details?

butonic commented 1 month ago

Reproducer:

1. start first upload

POST https://cloud.ocis.test/remote.php/webdav
Tus-Resumable: 1.0.0
Upload-Length: 100
Upload-Metadata: filename TW91bnRhaW4gRHVjay00LjE1LjcuMjIwNDcuemlw, mtime 1712677748, filetype application/zip,
Content-Length: 0
Authorization: Basic ZWluc3RlaW46cmVsYXRpdml0eQ==
HTTP/1.1 201 Created
Access-Control-Allow-Headers: Tus-Resumable, Upload-Length, Upload-Metadata, If-Match
Access-Control-Expose-Headers: Tus-Resumable, Upload-Offset, Location
Content-Length: 0
Content-Security-Policy: child-src 'self'; connect-src 'self'; default-src 'none'; font-src 'self'; frame-ancestors 'none'; frame-src 'self' https://embed.diagrams.net/ https://onlyoffice.ocis.test/ https://collabora.ocis.test/; img-src 'self' data: blob: https://onlyoffice.ocis.test/ https://collabora.ocis.test/; manifest-src 'self'; media-src 'self'; object-src 'self' blob:; script-src 'self' 'unsafe-inline'; style-src 'self' 'unsafe-inline'
Date: Mon, 30 Sep 2024 14:35:45 GMT
Location: https://cloud.ocis.test/data/eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJyZXZhIiwiZXhwIjoxNzI3NzkzMzQ1LCJpYXQiOjE3Mjc3MDY5NDUsInRhcmdldCI6Imh0dHA6Ly9sb2NhbGhvc3Q6OTE1OC9kYXRhL3R1cy9kNDhmODhjMi04NTcyLTQzN2MtOGQ1Mi0xYjI3ZmY2NmY3ODcifQ.AwGxDWJZLOsN2_Eb7t1lRHYlHeZjJ6SGTH9r9HzjZDY
Referrer-Policy: strict-origin-when-cross-origin
Strict-Transport-Security: max-age=315360000; preload
Tus-Extension: creation,creation-with-upload,checksum,expiration
Tus-Resumable: 1.0.0
Vary: Accept-Encoding, Origin
X-Content-Type-Options: nosniff
X-Frame-Options: SAMEORIGIN
X-Permitted-Cross-Domain-Policies: none
X-Request-Id: covu/90cssA1vLe-002709
X-Robots-Tag: none
X-Xss-Protection: 1; mode=block

2. start second upload

POST https://cloud.ocis.test/remote.php/webdav
Tus-Resumable: 1.0.0
Upload-Length: 100
Upload-Metadata: filename TW91bnRhaW4gRHVjay00LjE1LjcuMjIwNDcuemlw, mtime 1712677748, filetype application/zip,
Content-Length: 0
Authorization: Basic ZWluc3RlaW46cmVsYXRpdml0eQ==
HTTP/1.1 201 Created
Access-Control-Allow-Headers: Tus-Resumable, Upload-Length, Upload-Metadata, If-Match
Access-Control-Expose-Headers: Tus-Resumable, Upload-Offset, Location
Content-Length: 0
Content-Security-Policy: child-src 'self'; connect-src 'self'; default-src 'none'; font-src 'self'; frame-ancestors 'none'; frame-src 'self' https://embed.diagrams.net/ https://onlyoffice.ocis.test/ https://collabora.ocis.test/; img-src 'self' data: blob: https://onlyoffice.ocis.test/ https://collabora.ocis.test/; manifest-src 'self'; media-src 'self'; object-src 'self' blob:; script-src 'self' 'unsafe-inline'; style-src 'self' 'unsafe-inline'
Date: Mon, 30 Sep 2024 14:36:24 GMT
Location: https://cloud.ocis.test/data/eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJyZXZhIiwiZXhwIjoxNzI3NzkzMzg0LCJpYXQiOjE3Mjc3MDY5ODQsInRhcmdldCI6Imh0dHA6Ly9sb2NhbGhvc3Q6OTE1OC9kYXRhL3R1cy9iZjg4NzJlMy0yY2U2LTQxZDQtODgzNy05ODM2NDE0MmY3N2MifQ.oRFKGJzrgzUvA3g7a1XaPxA-bu9spSlU9XKj-lXsTmQ
Referrer-Policy: strict-origin-when-cross-origin
Strict-Transport-Security: max-age=315360000; preload
Tus-Extension: creation,creation-with-upload,checksum,expiration
Tus-Resumable: 1.0.0
Vary: Accept-Encoding, Origin
X-Content-Type-Options: nosniff
X-Frame-Options: SAMEORIGIN
X-Permitted-Cross-Domain-Policies: none
X-Request-Id: covu/90cssA1vLe-002719
X-Robots-Tag: none
X-Xss-Protection: 1; mode=block

3. finish second upload

PATCH https://cloud.ocis.test/data/eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJyZXZhIiwiZXhwIjoxNzI3NzkzMzg0LCJpYXQiOjE3Mjc3MDY5ODQsInRhcmdldCI6Imh0dHA6Ly9sb2NhbGhvc3Q6OTE1OC9kYXRhL3R1cy9iZjg4NzJlMy0yY2U2LTQxZDQtODgzNy05ODM2NDE0MmY3N2MifQ.oRFKGJzrgzUvA3g7a1XaPxA-bu9spSlU9XKj-lXsTmQ
Tus-Resumable: 1.0.0
Content-Length: 100
Upload-Offset: 0
Content-Type: application/offset+octet-stream

1234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890
HTTP/1.1 204 No Content
Content-Security-Policy: child-src 'self'; connect-src 'self'; default-src 'none'; font-src 'self'; frame-ancestors 'none'; frame-src 'self' https://embed.diagrams.net/ https://onlyoffice.ocis.test/ https://collabora.ocis.test/; img-src 'self' data: blob: https://onlyoffice.ocis.test/ https://collabora.ocis.test/; manifest-src 'self'; media-src 'self'; object-src 'self' blob:; script-src 'self' 'unsafe-inline'; style-src 'self' 'unsafe-inline'
Date: Mon, 30 Sep 2024 14:42:41 GMT
Oc-Fileid: storage-users-1$4c510ada-c86b-4815-8820-42cdf82c3d51!5495e4c1-dcaf-44b9-a653-24617d96f9e6
Referrer-Policy: strict-origin-when-cross-origin
Strict-Transport-Security: max-age=315360000; preload
Tus-Resumable: 1.0.0
Upload-Expires: 1727793384
Upload-Offset: 100
Vary: Accept-Encoding, Origin
X-Content-Type-Options: nosniff, nosniff
X-Frame-Options: SAMEORIGIN
X-Permitted-Cross-Domain-Policies: none
X-Request-Id: covu/90cssA1vLe-002845
X-Robots-Tag: none
X-Xss-Protection: 1; mode=block

4. finish first upload

PATCH https://cloud.ocis.test/data/eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJyZXZhIiwiZXhwIjoxNzI3NzkzMzQ1LCJpYXQiOjE3Mjc3MDY5NDUsInRhcmdldCI6Imh0dHA6Ly9sb2NhbGhvc3Q6OTE1OC9kYXRhL3R1cy9kNDhmODhjMi04NTcyLTQzN2MtOGQ1Mi0xYjI3ZmY2NmY3ODcifQ.AwGxDWJZLOsN2_Eb7t1lRHYlHeZjJ6SGTH9r9HzjZDY
Tus-Resumable: 1.0.0
Content-Length: 100
Upload-Offset: 0
Content-Type: application/offset+octet-stream

1234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890
HTTP/1.1 500 Internal Server Error
Content-Length: 0
Content-Security-Policy: child-src 'self'; connect-src 'self'; default-src 'none'; font-src 'self'; frame-ancestors 'none'; frame-src 'self' https://embed.diagrams.net/ https://onlyoffice.ocis.test/ https://collabora.ocis.test/; img-src 'self' data: blob: https://onlyoffice.ocis.test/ https://collabora.ocis.test/; manifest-src 'self'; media-src 'self'; object-src 'self' blob:; script-src 'self' 'unsafe-inline'; style-src 'self' 'unsafe-inline'
Date: Mon, 30 Sep 2024 14:44:19 GMT
Referrer-Policy: strict-origin-when-cross-origin
Strict-Transport-Security: max-age=315360000; preload
Vary: Accept-Encoding, Origin
X-Content-Type-Options: nosniff
X-Frame-Options: SAMEORIGIN
X-Permitted-Cross-Domain-Policies: none
X-Request-Id: covu/90cssA1vLe-002876
X-Robots-Tag: none
X-Xss-Protection: 1; mode=block

server panics

{"level":"info","pid":3782226,"pid":3782226,"childNameLink":"/home/jfd/.ocis/storage/users/spaces/4c/510ada-c86b-4815-8820-42cdf82c3d51/nodes/4c/51/0a/da/-c86b-4815-8820-42cdf82c3d51/Mountain Duck-4.15.7.22047.zip","relativeNodePath":"../../../../../13/16/2a/03/-ec89-417b-8da1-bd1e7e037d94","time":"2024-09-30T16:44:19+02:00","caller":"/home/jfd/Repositories/reva/pkg/storage/utils/decomposedfs/upload/upload.go:165","message":"initNewNode: creating symlink"}
{"level":"info","pid":3782226,"pid":3782226,"childNameLink":"/home/jfd/.ocis/storage/users/spaces/4c/510ada-c86b-4815-8820-42cdf82c3d51/nodes/4c/51/0a/da/-c86b-4815-8820-42cdf82c3d51/Mountain Duck-4.15.7.22047.zip","relativeNodePath":"../../../../../13/16/2a/03/-ec89-417b-8da1-bd1e7e037d94","error":"symlink ../../../../../13/16/2a/03/-ec89-417b-8da1-bd1e7e037d94 /home/jfd/.ocis/storage/users/spaces/4c/510ada-c86b-4815-8820-42cdf82c3d51/nodes/4c/51/0a/da/-c86b-4815-8820-42cdf82c3d51/Mountain Duck-4.15.7.22047.zip: file exists","time":"2024-09-30T16:44:19+02:00","caller":"/home/jfd/Repositories/reva/pkg/storage/utils/decomposedfs/upload/upload.go:165","message":"initNewNode: symlink failed"}
{"level":"info","pid":3782226,"pid":3782226,"childNameLink":"/home/jfd/.ocis/storage/users/spaces/4c/510ada-c86b-4815-8820-42cdf82c3d51/nodes/4c/51/0a/da/-c86b-4815-8820-42cdf82c3d51/Mountain Duck-4.15.7.22047.zip","relativeNodePath":"../../../../../13/16/2a/03/-ec89-417b-8da1-bd1e7e037d94","error":"symlink ../../../../../13/16/2a/03/-ec89-417b-8da1-bd1e7e037d94 /home/jfd/.ocis/storage/users/spaces/4c/510ada-c86b-4815-8820-42cdf82c3d51/nodes/4c/51/0a/da/-c86b-4815-8820-42cdf82c3d51/Mountain Duck-4.15.7.22047.zip: file exists","time":"2024-09-30T16:44:19+02:00","caller":"/home/jfd/Repositories/reva/pkg/storage/utils/decomposedfs/upload/upload.go:165","message":"initNewNode: symlink already exists"}
{"level":"error","pid":3782226,"pid":3782226,"path":"/home/jfd/.ocis/storage/users/spaces/4c/510ada-c86b-4815-8820-42cdf82c3d51/nodes/13/16/2a/03/-ec89-417b-8da1-bd1e7e037d94","error":"error: already exists: Mountain Duck-4.15.7.22047.zip","time":"2024-09-30T16:44:19+02:00","caller":"/home/jfd/go/pkg/mod/github.com/tus/tusd/v2@v2.5.0/pkg/handler/unrouted_handler.go:947","message":"failed to init new node"}
{"level":"error","pid":3782226,"pid":3782226,"path":"/home/jfd/.ocis/storage/users/spaces/4c/510ada-c86b-4815-8820-42cdf82c3d51/nodes/13/16/2a/03/-ec89-417b-8da1-bd1e7e037d94","nodeid":"13162a03-ec89-417b-8da1-bd1e7e037d94","attrs":{},"messagepack":"","time":"2024-09-30T16:44:19+02:00","caller":"/home/jfd/Repositories/reva/pkg/storage/utils/decomposedfs/upload/upload.go:302","message":"missing parent id"}
{"level":"error","pid":3782226,"pid":3782226,"error":"internal error: Missing parent ID on node","sessionid":"d48f88c2-8572-437c-8d52-1b27ff66f787","time":"2024-09-30T16:44:19+02:00","caller":"/home/jfd/Repositories/reva/pkg/storage/utils/decomposedfs/upload/upload.go:167","message":"reading node for session failed"}
2024/09/30 16:44:19 http: panic serving 127.0.0.1:59686: runtime error: invalid memory address or nil pointer dereference
goroutine 131700 [running]:
net/http.(*conn).serve.func1()
    /usr/lib/go/src/net/http/server.go:1947 +0x13f
panic({0x4776e20?, 0x7a381b0?})
    /usr/lib/go/src/runtime/panic.go:785 +0x136
github.com/cs3org/reva/v2/pkg/storage/utils/decomposedfs/node.(*Node).InternalPath(0x0)
    /home/jfd/Repositories/reva/pkg/storage/utils/decomposedfs/node/node.go:557 +0x22
github.com/cs3org/reva/v2/pkg/storage/utils/decomposedfs/node.(*Node).Xattr(0x0, {0x5ff5638, 0xc00573f8c0}, {0x4e4b836, 0x14})
    /home/jfd/Repositories/reva/pkg/storage/utils/decomposedfs/node/xattrs.go:148 +0x67
github.com/cs3org/reva/v2/pkg/storage/utils/decomposedfs/node.(*Node).XattrString(0x0, {0x5ff5638, 0xc00573f8c0}, {0x4e4b836, 0x14})
    /home/jfd/Repositories/reva/pkg/storage/utils/decomposedfs/node/xattrs.go:178 +0x93
github.com/cs3org/reva/v2/pkg/storage/utils/decomposedfs/node.(*Node).ProcessingID(0x0, {0x5ff5638, 0xc00573f8c0})
    /home/jfd/Repositories/reva/pkg/storage/utils/decomposedfs/node/node.go:1258 +0x73
github.com/cs3org/reva/v2/pkg/storage/utils/decomposedfs/upload.(*OcisSession).Cleanup(0xc003d647e0, 0x1, 0x1, 0x1)
    /home/jfd/Repositories/reva/pkg/storage/utils/decomposedfs/upload/upload.go:324 +0x51a
github.com/cs3org/reva/v2/pkg/storage/utils/decomposedfs/upload.OcisStore.Cleanup({{0x60228e0, 0xc0007eb080}, {0x6011c20, 0xc0022bcf30}, {0x6015b08, 0xc002bd93b0}, {0x5ff7968, 0x7d35340}, {0xc001701320, 0x1d}, ...}, ...)
    /home/jfd/Repositories/reva/pkg/storage/utils/decomposedfs/upload/store.go:181 +0x242
github.com/cs3org/reva/v2/pkg/storage/utils/decomposedfs/upload.(*OcisSession).FinishUpload(0xc003d647e0, {0x5ff5638, 0xc002b5f470})
    /home/jfd/Repositories/reva/pkg/storage/utils/decomposedfs/upload/upload.go:167 +0x1151
github.com/tus/tusd/v2/pkg/handler.(*UnroutedHandler).finishUploadIfComplete(0xc001fe1500, 0xc000dce7d0, {0xcc, {0x0, 0x0}, 0xc002b5f1a0}, {0x5ff7540, 0xc003d647e0}, {{0xc0057b8240, 0x24}, ...})
    /home/jfd/go/pkg/mod/github.com/tus/tusd/v2@v2.5.0/pkg/handler/unrouted_handler.go:947 +0xef
github.com/tus/tusd/v2/pkg/handler.(*UnroutedHandler).writeChunk(0xc001fe1500, 0xc000dce7d0, {0xcc, {0x0, 0x0}, 0xc002b5f1a0}, {0x5ff7540, 0xc003d647e0}, {{0xc0057b8240, 0x24}, ...})
    /home/jfd/go/pkg/mod/github.com/tus/tusd/v2@v2.5.0/pkg/handler/unrouted_handler.go:931 +0xd65
github.com/tus/tusd/v2/pkg/handler.(*UnroutedHandler).PatchFile(0xc001fe1500, {0x75ea10857f38, 0xc002b5eb70}, 0xc0024ff540)
    /home/jfd/go/pkg/mod/github.com/tus/tusd/v2@v2.5.0/pkg/handler/unrouted_handler.go:794 +0x1006
github.com/cs3org/reva/v2/pkg/rhttp/datatx/manager/tus.(*manager).Handler.func2({0x75ea10857f38, 0xc002b5eb70}, 0xc0024ff540)
    /home/jfd/Repositories/reva/pkg/rhttp/datatx/manager/tus/tus.go:177 +0x4ef
net/http.HandlerFunc.ServeHTTP(0xc003504f40, {0x75ea10857f38, 0xc002b5eb70}, 0xc0024ff540)
    /usr/lib/go/src/net/http/server.go:2220 +0x33
github.com/tus/tusd/v2/pkg/handler.(*UnroutedHandler).Middleware.func1({0x75ea10857f38, 0xc002b5eb70}, 0xc0024ff540)
    /home/jfd/go/pkg/mod/github.com/tus/tusd/v2@v2.5.0/pkg/handler/unrouted_handler.go:267 +0x112c
net/http.HandlerFunc.ServeHTTP(0xc003504f60, {0x75ea10857f38, 0xc002b5eb70}, 0xc0024ff2c0)
    /usr/lib/go/src/net/http/server.go:2220 +0x33
github.com/cs3org/reva/v2/internal/http/services/dataprovider.(*svc).setHandler.func1({0x75ea10857f38, 0xc002b5eb70}, 0xc0024ff2c0)
    /home/jfd/Repositories/reva/internal/http/services/dataprovider/dataprovider.go:185 +0x32c
net/http.HandlerFunc.ServeHTTP(0xc00350f980, {0x75ea10857f38, 0xc002b5eb70}, 0xc0024ff2c0)
    /usr/lib/go/src/net/http/server.go:2220 +0x33
github.com/cs3org/reva/v2/pkg/rhttp.traceHandler.func1({0x75ea10857f38, 0xc002b5eb70}, 0xc0024ff180)
    /home/jfd/Repositories/reva/pkg/rhttp/rhttp.go:316 +0x355
net/http.HandlerFunc.ServeHTTP(0xc002e72b80, {0x75ea10857f38, 0xc002b5eb70}, 0xc0024ff180)
    /usr/lib/go/src/net/http/server.go:2220 +0x33
github.com/cs3org/reva/v2/pkg/rhttp.(*Server).getHandler.func1({0x75ea10857f38, 0xc002b5eb70}, 0xc0024ff180)
    /home/jfd/Repositories/reva/pkg/rhttp/rhttp.go:249 +0x3d2
net/http.HandlerFunc.ServeHTTP(0xc00350fd60, {0x75ea10857f38, 0xc002b5eb70}, 0xc0024ff180)
    /usr/lib/go/src/net/http/server.go:2220 +0x33
github.com/cs3org/reva/v2/pkg/rhttp.traceHandler.func1({0x75ea10857f38, 0xc002b5eb70}, 0xc0024fef00)
    /home/jfd/Repositories/reva/pkg/rhttp/rhttp.go:316 +0x355
net/http.HandlerFunc.ServeHTTP(0xc002e72bc0, {0x75ea10857f38, 0xc002b5eb70}, 0xc0024fef00)
    /usr/lib/go/src/net/http/server.go:2220 +0x33
github.com/go-chi/chi/v5/middleware.RequestID.func1({0x75ea10857f38, 0xc002b5eb70}, 0xc0024fec80)
    /home/jfd/go/pkg/mod/github.com/go-chi/chi/v5@v5.1.0/middleware/request_id.go:76 +0x253
net/http.HandlerFunc.ServeHTTP(0xc002e68a80, {0x75ea10857f38, 0xc002b5eb70}, 0xc0024fec80)
    /usr/lib/go/src/net/http/server.go:2220 +0x33
github.com/cs3org/reva/v2/internal/http/interceptors/requestid.requestIDHandler.ServeHTTP({{0x5fccb80, 0xc002e68a80}}, {0x75ea10857f38, 0xc002b5eb70}, 0xc0024fec80)
    /home/jfd/Repositories/reva/internal/http/interceptors/requestid/requestid.go:53 +0x42
github.com/cs3org/reva/v2/pkg/rhttp.traceHandler.func1({0x75ea10857f38, 0xc002b5eb70}, 0xc0024fe500)
    /home/jfd/Repositories/reva/pkg/rhttp/rhttp.go:316 +0x355
net/http.HandlerFunc.ServeHTTP(0xc002e72c00, {0x75ea10857f38, 0xc002b5eb70}, 0xc0024fe500)
    /usr/lib/go/src/net/http/server.go:2220 +0x33
github.com/cs3org/reva/v2/internal/http/interceptors/auth.New.func2.1({0x75ea10857f38, 0xc002b5eb70}, 0xc0024fe500)
    /home/jfd/Repositories/reva/internal/http/interceptors/auth/auth.go:212 +0x965
net/http.HandlerFunc.ServeHTTP(0xc00351e750, {0x75ea10857f38, 0xc002b5eb70}, 0xc0024fe500)
    /usr/lib/go/src/net/http/server.go:2220 +0x33
github.com/cs3org/reva/v2/pkg/rhttp.traceHandler.func1({0x75ea10857f38, 0xc002b5eb70}, 0xc0024fe3c0)
    /home/jfd/Repositories/reva/pkg/rhttp/rhttp.go:316 +0x355
net/http.HandlerFunc.ServeHTTP(0xc002e72c40, {0x75ea10857f38, 0xc002b5eb70}, 0xc0024fe3c0)
    /usr/lib/go/src/net/http/server.go:2220 +0x33
github.com/cs3org/reva/v2/internal/http/interceptors/log.loggingHandler.ServeHTTP({{0x5fccb80, 0xc002e72c40}}, {0x5febdd0, 0xc002abe540}, 0xc0024fe3c0)
    /home/jfd/Repositories/reva/internal/http/interceptors/log/log.go:57 +0x15f
github.com/cs3org/reva/v2/pkg/rhttp.traceHandler.func1({0x5febdd0, 0xc002abe540}, 0xc0024fe280)
    /home/jfd/Repositories/reva/pkg/rhttp/rhttp.go:316 +0x355
net/http.HandlerFunc.ServeHTTP(0xc002e72c80, {0x5febdd0, 0xc002abe540}, 0xc0024fe280)
    /usr/lib/go/src/net/http/server.go:2220 +0x33
github.com/cs3org/reva/v2/internal/http/interceptors/appctx.handler.func1({0x5febdd0, 0xc002abe540}, 0xc0024fe280)
    /home/jfd/Repositories/reva/internal/http/interceptors/appctx/appctx.go:58 +0x55c
net/http.HandlerFunc.ServeHTTP(0xc003520500, {0x5febdd0, 0xc002abe540}, 0xc0024fe140)
    /usr/lib/go/src/net/http/server.go:2220 +0x33
net/http.serverHandler.ServeHTTP({0xc002c7c690}, {0x5febdd0, 0xc002abe540}, 0xc0024fe140)
    /usr/lib/go/src/net/http/server.go:3210 +0x257
net/http.(*conn).serve(0xc005df61b0, {0x5ff5670, 0xc000dce460})
    /usr/lib/go/src/net/http/server.go:2092 +0x1ab5
created by net/http.(*Server).Serve in goroutine 503
    /usr/lib/go/src/net/http/server.go:3360 +0xa9a
2024-09-30T16:44:19+02:00 ERR error doing PATCH request to data service error="Patch \"http://localhost:9158/data/tus/d48f88c2-8572-437c-8d52-1b27ff66f787\": EOF" line=/home/jfd/Repositories/reva/internal/http/services/datagateway/datagateway.go:200 pkg=rhttp request-id=covu/90cssA1vLe-002877 service=frontend traceid=9721365104912b72b84cafe2bbf1eacf
2024-09-30T16:44:19+02:00 ERR http end="30/Sep/2024:16:44:19 +0200" host=127.0.0.1 line=/home/jfd/Repositories/reva/internal/http/interceptors/log/log.go:112 method=PATCH pkg=rhttp proto=HTTP/1.1 service=frontend size=0 start="30/Sep/2024:16:44:19 +0200" status=500 time_ns=10770477 traceid=9721365104912b72b84cafe2bbf1eacf uri=/data/eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJyZXZhIiwiZXhwIjoxNzI3NzkzMzQ1LCJpYXQiOjE3Mjc3MDY5NDUsInRhcmdldCI6Imh0dHA6Ly9sb2NhbGhvc3Q6OTE1OC9kYXRhL3R1cy9kNDhmODhjMi04NTcyLTQzN2MtOGQ1Mi0xYjI3ZmY2NmY3ODcifQ.AwGxDWJZLOsN2_Eb7t1lRHYlHeZjJ6SGTH9r9HzjZDY url=/eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJyZXZhIiwiZXhwIjoxNzI3NzkzMzQ1LCJpYXQiOjE3Mjc3MDY5NDUsInRhcmdldCI6Imh0dHA6Ly9sb2NhbGhvc3Q6OTE1OC9kYXRhL3R1cy9kNDhmODhjMi04NTcyLTQzN2MtOGQ1Mi0xYjI3ZmY2NmY3ODcifQ.AwGxDWJZLOsN2_Eb7t1lRHYlHeZjJ6SGTH9r9HzjZDY
butonic commented 1 month ago

hm decomposedfs/node/node.go:557 can have multiple nil pointers:

func (n *Node) InternalPath() string {
    return n.lu.InternalPath(n.SpaceID, n.ID) // 557
}

called by

func (n *Node) Xattr(ctx context.Context, key string) ([]byte, error) {
    path := n.InternalPath()

called by

func (n *Node) XattrString(ctx context.Context, key string) (string, error) {
    b, err := n.Xattr(ctx, key)

called by

func (n *Node) ProcessingID(ctx context.Context) (string, error) {
    v, err := n.XattrString(ctx, prefixes.StatusPrefix)

called by

func (session *OcisSession) Cleanup(revertNodeMetadata, cleanBin, cleanInfo bool) {
    ctx := session.Context(context.Background())

    if revertNodeMetadata {
        n, err := session.Node(ctx)
        if err != nil {
            appctx.GetLogger(ctx).Error().Err(err).Str("sessionid", session.ID()).Msg("reading node for session failed")
        }
        if session.NodeExists() && session.info.MetaData["versionsPath"] != "" {
            p := session.info.MetaData["versionsPath"]
            if err := session.store.lu.CopyMetadata(ctx, p, n.InternalPath(), func(attributeName string, value []byte) (newValue []byte, copy bool) {
                return value, strings.HasPrefix(attributeName, prefixes.ChecksumPrefix) ||
                    attributeName == prefixes.TypeAttr ||
                    attributeName == prefixes.BlobIDAttr ||
                    attributeName == prefixes.BlobsizeAttr ||
                    attributeName == prefixes.MTimeAttr
            }, true); err != nil {
                appctx.GetLogger(ctx).Info().Str("versionpath", p).Str("nodepath", n.InternalPath()).Err(err).Msg("renaming version node failed")
            }

            if err := os.RemoveAll(p); err != nil {
                appctx.GetLogger(ctx).Info().Str("versionpath", p).Str("nodepath", n.InternalPath()).Err(err).Msg("error removing version")
            }

        } else {
            // if no other upload session is in progress (processing id != session id) or has finished (processing id == "")
            latestSession, err := n.ProcessingID(ctx) // <- here

hm, it seems the session did not return a node:

n, err := session.Node(ctx)
if err != nil {
    appctx.GetLogger(ctx).Error().Err(err).Str("sessionid", session.ID()).Msg("reading node for session failed")
}

even if we get an error we still try to use n

👀

sure enough we log this right before the panic:

{
  "level":"error",
  "pid":3782226,
  "pid":3782226,
  "error":"internal error: Missing parent ID on node",
  "sessionid":"d48f88c2-8572-437c-8d52-1b27ff66f787",
  "time":"2024-09-30T16:44:19+02:00",
  "caller":"/home/jfd/Repositories/reva/pkg/storage/utils/decomposedfs/upload/upload.go:167",
  "message":"reading node for session failed"
}
butonic commented 1 month ago

Dropping this here as a .http file for httpYac to test this:

@baseUrl = https://cloud.ocis.test
@username = einstein
@password = relativity

{{
  filename = new Buffer($random.alphabetic(50)+'.test', 'utf-8').toString('base64');
}}

// @title initiate first upload
// @name upload1
POST {{baseUrl}}/remote.php/webdav
Tus-Resumable: 1.0.0
Upload-Length: 10
Upload-Metadata: filename {{filename}}, mtime 1712677748, filetype application/zip,
Content-Length: 0
Authorization: Basic {{username}}:{{password}}

?? status == 201 Created

{{
  uploadlocation1 = response.headers.location;
}}

###
// @title initiate second upload
// @name upload2
POST {{baseUrl}}/remote.php/webdav
Tus-Resumable: 1.0.0
Upload-Length: 10
Upload-Metadata: filename {{filename}}, mtime 1712677748, filetype application/zip,
Content-Length: 0
Authorization: Basic {{username}}:{{password}}

?? status == 201 Created

{{
  uploadlocation2 = response.headers.location;
}}

###
// @title finish second upload
// @name patch2
// @ref upload2
PATCH {{uploadlocation2}}
Tus-Resumable: 1.0.0
Content-Length: 10
Upload-Offset: 0
Content-Type: application/offset+octet-stream

1234567890

?? status == 204 No Content

###
// @title finish first upload
// @description This request should fail because another upload has created the same file.
// @name patch1
// @ref upload1
PATCH {{uploadlocation1}}
Tus-Resumable: 1.0.0
Content-Length: 10
Upload-Offset: 0
Content-Type: application/offset+octet-stream

1234567890

?? status == 409 Precondtion Failed

to get rid of certificate errors use a .env file:

request_rejectUnauthorized=false
butonic commented 1 month ago

now, on to the actual problem. It only occurs when the file to be uploaded did not exist, yet.

butonic commented 1 month ago

reva fix in https://github.com/cs3org/reva/pull/4872

individual-it commented 1 month ago