Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Renaming a non existing resource should return 404 instead of internal server error #452

Closed
refs opened this issue Aug 13, 2020 · 2 comments
Labels

Comments

@refs
Copy link
Member

refs commented Aug 13, 2020

Context

This was found on #450 out of pure coincidence. Read the ticket for more context on the cause. This ticket deals with the side effect

Steps to Reproduce

  1. get to a state where you could rename a resource that doesn't exist anymore.
    1.1 perhaps the easiest way to do this is by checking out ocis at this point in time, or checkout on commit 57f4953a48f44205fa44c923951782917e89e4dd (that given Update deps 2020 07 22 #409 history was rewritten, if that's the case, point to the merge commit).
    1.2 make sure phoenix assets were not updated, if so, find the point on time they changed and checkout there.
  2. on owncloud/ocis root dir: go run cmd/ocis/main.go server
  3. go to: https://localhost:9200
  4. create a folder: folder1
  5. create a file: file.txt
  6. rename the file

expected results

  • Renaming works and no error dialog is displayed
  • The server handles moving a non existing resource returning a 404, not an internal server error.

observed results

  • an error dialog appears, but the rename takes places correctly

Root Cause

As explained in #450 there are 2 calls taking place, the first one works while the second one tries to rename a resource that no longer exists, and that causes the server to reply with a 500.

Server Logs

2020-08-13T11:26:41+02:00 INF unary code=OK end="13/Aug/2020:11:26:41 +0200" from=tcp://[::1]:56227 pkg=rgrpc service=reva start="13/Aug/2020:11:26:41 +0200" time_ns=1930478 traceid=d2ba5e474bcf76b94fc42e4e23ed5926 uri=/cs3.gateway.v1beta1.GatewayAPI/Move user-agent=grpc-
go/1.26.0
2020-08-13T11:26:41+02:00 INF move request status move=CODE_OK pkg=rhttp service=reva traceid=d2ba5e474bcf76b94fc42e4e23ed5926
2020-08-13T11:26:41+02:00 ERR Users/aunger/go/pkg/mod/github.com/cs3org/reva@v1.1.1-0.20200812182703-f3251947b9a8/internal/grpc/services/storageprovider/storageprovider.go:439 > error moving file error="ocfs: error moving /var/tmp/reva/data/4c510ada-c86b-4815-8820-42cdf82c3d51/files/folder1/asdf.txt to /var/tmp/reva/data/4c510ada-c86b-4815-8820-42cdf82c3d51/files/folder1/world.txt: rename /var/tmp/reva/data/4c510ada-c86b-4815-8820-42cdf82c3d51/files/folder1/asdf.txt /var/tmp/reva/data/4c510ada-c86b-4815-8820-42cdf82c3d51/files/folder1/world.txt: no such file or directory" pkg=rgrpc service=reva traceid=90cc225b913bd91537c86b0bf1a5f9fa
2020-08-13T11:26:41+02:00 INF unary code=OK end="13/Aug/2020:11:26:41 +0200" from=tcp://[::1]:56200 pkg=rgrpc service=reva start="13/Aug/2020:11:26:41 +0200" time_ns=433575 traceid=90cc225b913bd91537c86b0bf1a5f9fa uri=/cs3.storage.provider.v1beta1.ProviderAPI/Move user-agent=grpc-go/1.26.0
2020-08-13T11:26:41+02:00 INF unary code=OK end="13/Aug/2020:11:26:41 +0200" from=tcp://[::1]:56199 pkg=rgrpc service=reva start="13/Aug/2020:11:26:41 +0200" time_ns=75671 traceid=d2ba5e474bcf76b94fc42e4e23ed5926 uri=/cs3.storage.registry.v1beta1.RegistryAPI/GetStorageProvider user-agent=grpc-go/1.26.0
2020-08-13T11:26:41+02:00 INF unary code=OK end="13/Aug/2020:11:26:41 +0200" from=tcp://[::1]:56227 pkg=rgrpc service=reva start="13/Aug/2020:11:26:41 +0200" time_ns=1587969 traceid=90cc225b913bd91537c86b0bf1a5f9fa uri=/cs3.gateway.v1beta1.GatewayAPI/Move user-agent=grpc-go/1.26.0
2020-08-13T11:26:41+02:00 ERR error handling move request move_request=CODE_INTERNAL pkg=rhttp service=reva traceid=90cc225b913bd91537c86b0bf1a5f9fa
2020-08-13T11:26:41+02:00 ERR http end="13/Aug/2020:11:26:41 +0200" host=::1 method=MOVE pkg=rhttp proto=HTTP/1.1 service=reva size=0 start="13/Aug/2020:11:26:41 +0200" status=500 time_ns=7662126 traceid=90cc225b913bd91537c86b0bf1a5f9fa uri=/remote.php/webdav/folder1/asdf.txt url=/remote.php/webdav/folder1/asdf.txt
2020-08-13T11:26:41+02:00 INF unary code=OK end="13/Aug/2020:11:26:41 +0200" from=tcp://[::1]:56200 pkg=rgrpc service=reva start="13/Aug/2020:11:26:41 +0200" time_ns=635580 traceid=d2ba5e474bcf76b94fc42e4e23ed5926 uri=/cs3.storage.provider.v1beta1.ProviderAPI/Stat user-agent=grpc-go/1.26.0
2020-08-13T11:26:41+02:00 INF unary code=OK end="13/Aug/2020:11:26:41 +0200" from=tcp://[::1]:56227 pkg=rgrpc service=reva start="13/Aug/2020:11:26:41 +0200" time_ns=1592376 traceid=d2ba5e474bcf76b94fc42e4e23ed5926 uri=/cs3.gateway.v1beta1.GatewayAPI/Stat user-agent=grpc-go/1.26.0
2020-08-13T11:26:41+02:00 INF http end="13/Aug/2020:11:26:41 +0200" host=::1 method=MOVE pkg=rhttp proto=HTTP/1.1 service=reva size=0 start="13/Aug/2020:11:26:41 +0200" status=201 time_ns=10688575 traceid=d2ba5e474bcf76b94fc42e4e23ed5926 uri=/remote.php/webdav/folder1/asdf.txt url=/remote.php/webdav/folder1/asdf.txt

Browser logs

Screenshot 2020-08-13 at 11 28 16

@refs refs added bug and removed bug labels Aug 13, 2020
@PVince81
Copy link
Contributor

is this reproducible with curl ?

I think the bug should be triggerable without relying on that other Phoenix bug.

@refs
Copy link
Member Author

refs commented Aug 13, 2020

Edit: the API looks like it correctly returns 404 when trying to delete a resource that doesn't exist. However when renaming a file to the same name, the following occurs:

curl 'https://localhost:9200/remote.php/webdav/folder1/world.txt' \
  -X 'MOVE' \
  -H 'Connection: keep-alive' \
  -H 'Pragma: no-cache' \
  -H 'Cache-Control: no-cache' \
  -H 'authorization: Bearer eyJhbGciOiJQUzI1NiIsImtpZCI6IiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJwaG9lbml4IiwiZXhwIjoxNTk3MzEyMjkwLCJqdGkiOiJxS0E4VTN5ckpvSUZ4bDZoaC1Tcm1sVlJYUG9oM011VyIsImlhdCI6MTU5NzMxMTY5MCwiaXNzIjoiaHR0cHM6Ly9sb2NhbGhvc3Q6OTIwMCIsInN1YiI6Ilh0U2lfbWl5V1NCLXBrdkdueFBvQzVBNGZsaWgwVUNMZ3ZVN2NMd2ptakNLWDdGWW4ySFdrNnJSQ0V1eTJHNXFBeV95TVFjX0ZLOWFORmhVTXJYMnBRQGtvbm5lY3QiLCJrYy5pc0FjY2Vzc1Rva2VuIjp0cnVlLCJrYy5hdXRob3JpemVkU2NvcGVzIjpbInByb2ZpbGUiLCJlbWFpbCIsIm9wZW5pZCJdLCJrYy5pZGVudGl0eSI6eyJrYy5pLmRuIjoiZWluc3RlaW4iLCJrYy5pLmlkIjoiY249ZWluc3RlaW4sb3U9dXNlcnMsZGM9ZXhhbXBsZSxkYz1vcmciLCJrYy5pLnVuIjoiZWluc3RlaW4ifSwia2MucHJvdmlkZXIiOiJpZGVudGlmaWVyLWxkYXAifQ.dhqFKEQULZ0dM38C1BQ8-zuWKQSA75JdNxnbKxXQcIPD_M4FbO_znNEsl76VaGrlt2t9XZgHWapqGwRR0ZQoHmpEkTIxEHdwlnq6WaiUBKKLUf2Q4x-EOc0aZA7iCHFQbNT5n-9PXU1CsndZQCivV-k97rJwqZulSiF3qdH3ZmlEqqcZRezbWofLLeTvg07r1UC9UcO5cLk5i6se-MadED4MezijBx723D5eqCisFJ_Nmocxof7YAh3wnqcMemC3mGUG9oH1es2qeCKYLaIIPgaPV1AVFIWZVlLBR0IY2EqQ7LNkrBfmGKLIT9Bi8i0aw4waLyUcrydEh-yLrh4B7g' \
  -H 'X-Requested-With: XMLHttpRequest' \
  -H 'Destination: https://localhost:9200/remote.php/webdav/folder1/world.txt' \
  -H 'User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/84.0.4147.125 Safari/537.36' \
  -H 'OCS-APIREQUEST: true' \
  -H 'Accept: */*' \
  -H 'Origin: https://localhost:9200' \
  -H 'Sec-Fetch-Site: same-origin' \
  -H 'Sec-Fetch-Mode: cors' \
  -H 'Sec-Fetch-Dest: empty' \
  -H 'Referer: https://localhost:9200/' \
  -H 'Accept-Language: en,es-ES;q=0.9,es;q=0.8' \
  --compressed \
  --insecure

preconditions

You will need a valid access token.

Observed

We can trigger a 500 by setting the Destination to the same value as the target url, in the example above, set Destination to https://localhost:9200/remote.php/webdav/folder1/world.txt.

Server Logs

2020-08-13T12:22:41+02:00 ERR Users/aunger/go/pkg/mod/github.com/cs3org/reva@v1.1.1-0.20200812182703-f3251947b9a8/internal/grpc/services/storageprovider/storageprovider.go:439 > error moving file error="ocfs: error moving /var/tmp/reva/data/4c510ada-c86b-4815-8820-42cdf82c3d51/files/folder1/test.txt to /var/tmp/reva/data/4c510ada-c86b-4815-8820-42cdf82c3d51/files/folder1/test.txt: rename /var/tmp/reva/data/4c510ada-c86b-4815-8820-42cdf82c3d51/files/folder1/test.txt /var/tmp/reva/data/4c510ada-c86b-4815-8820-42cdf82c3d51/files/folder1/test.txt: no such file or directory" pkg=rgrpc service=reva traceid=fe1d5d79547e4b1caec21982c920d17c
2020-08-13T12:22:41+02:00 INF unary code=OK end="13/Aug/2020:12:22:41 +0200" from=tcp://[::1]:56200 pkg=rgrpc service=reva start="13/Aug/2020:12:22:41 +0200" time_ns=625486 traceid=fe1d5d79547e4b1caec21982c920d17c uri=/cs3.storage.provider.v1beta1.ProviderAPI/Move user-agent=grpc-go/1.26.0
2020-08-13T12:22:41+02:00 INF unary code=OK end="13/Aug/2020:12:22:41 +0200" from=tcp://[::1]:56227 pkg=rgrpc service=reva start="13/Aug/2020:12:22:41 +0200" time_ns=5108486 traceid=fe1d5d79547e4b1caec21982c920d17c uri=/cs3.gateway.v1beta1.GatewayAPI/Move user-agent=grpc-go/1.26.0
2020-08-13T12:22:41+02:00 ERR error handling move request move_request=CODE_INTERNAL pkg=rhttp service=reva traceid=fe1d5d79547e4b1caec21982c920d17c
2020-08-13T12:22:41+02:00 ERR http end="13/Aug/2020:12:22:41 +0200" host=::1 method=MOVE pkg=rhttp proto=HTTP/1.1 service=reva size=0 start="13/Aug/2020:12:22:41 +0200" status=500 time_ns=29455632 traceid=fe1d5d79547e4b1caec21982c920d17c uri=/remote.php/webdav/folder1/test.txt url=/remote.php/webdav/folder1/test.txt

refs pushed a commit that referenced this issue Sep 18, 2020
@refs refs closed this as completed Jan 12, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

2 participants