search

owncloud / ocis

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

Uploads fail with unknown error on macOS server #8368

Open prohtex opened 7 months ago

prohtex commented 7 months ago

Hi All, I'm a longtime OC user excited to move to OCIS after experiencing issues with large file uploads over the years. I love OC and OCIS looks really fantastic, and seems to do everything SeaFile can do. I am excited to get it working.

Unfortunately after setting it up, I am stumped. I have a fresh install of OCIS on a macOS 12.4 host with macports. I am using 5.0.0-RC3 Darwin AMD64 binary. I did a fairly vanilla setup with the server running as a launchctl service (the only way I could get this to work was running as root):

<!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
<plist version="1.0">
<dict>
    <key>Disabled</key>
    <false/>
    <key>EnvironmentVariables</key>
    <dict>
        <key>OCIS_BASE_DATA_PATH</key>
        <string>/Volumes/Store/ocis</string>
        <key>OCIS_CONFIG_DIR</key>
        <string>/opt/ocis</string>
        <key>OCIS_INSECURE</key>
        <string>true</string>
        <key>OCIS_LOG_LEVEL</key>
        <string>error</string>
        <key>OCIS_URL</key>
        <string>https://ocis.server.com</string>
        <key>PROXY_ENABLE_BASIC_AUTH</key>
        <string>true</string>
        <key>PROXY_HTTP_ADDR</key>
        <string>0.0.0.0:9200</string>
        <key>PROXY_TLS</key>
        <string>true</string>
    </dict>
    <key>InitGroups</key>
    <false/>
    <key>Label</key>
    <string>pfl.ocis</string>
    <key>LaunchEvents</key>
    <dict>
        <key></key>
        <dict/>
    </dict>
    <key>ProgramArguments</key>
    <array>
        <string>/opt/local/bin/ocis</string>
        <string>server</string>
    </array>
    <key>RunAtLoad</key>
    <true/>
    <key>StandardErrorPath</key>
    <string>/opt/daemon_output/ocis_stderr.log</string>
    <key>StandardOutPath</key>
    <string>/opt/daemon_output/ocis_stdout.log</string>
</dict>
</plist>

My apache config:

<VirtualHost *:80>
  ServerName ocis.server.com

  RewriteEngine On
  RewriteCond %{HTTPS} off
  RewriteRule (.*) https://%{HTTP_HOST}%{REQUEST_URI} [R=302,L,QSA]
</VirtualHost>

<VirtualHost *:443>
  ServerName ocis.server.com

  SSLProxyEngine on
  SSLProxyVerify none
  SSLProxyCheckPeerCN off
  SSLProxyCheckPeerName off
  SSLProxyCheckPeerExpire off

  ProxyPass / https://localhost:9200/
  ProxyPassReverse / https://localhost:9200/
  ProxyPreserveHost on

  SSLCertificateFile /opt/local/etc/letsencrypt/live/ocis.server.com/fullchain.pem
  SSLCertificateKeyFile /opt/local/etc/letsencrypt/live/ocis.server.com/privkey.pem

  Include /opt/local/etc/letsencrypt/options-ssl-apache.conf
  #SSLOpenSSLConfCmd DHParameters /opt/local/etc/letsencrypt/ssl-dhparams.pem

  ErrorLog "/opt/local/var/log/apache2/ocis_error_log"
  CustomLog "/opt/local/var/log/apache2/ocis_access_log" vcommon

</VirtualHost>

Things were going pretty well, although I did notice a lot of "token expired" errors. I also noticed that WebDAV was acting weird-I could mount the share using https://ocis.server.com/remote.php/webdav/, but it seemed to mount read/write while providing only "read" functionality. I was able to open, edit and save files, but the changes were not actually written. I could also upload files, which became 0 byte files on the server. Very odd.

Here are some initial logs.

error.txt

Then when I tried to upload some files, things got really interesting.

Screenshot 2024-02-05 at 2 56 07 PM

2024/02/05 14:01:23 http: TLS handshake error from xxx.xxx.xxx.xxx:55506: read tcp xxx.xxx.xxx.xxx:9200->xxx.xxx.xxx.xxx:55506: read: connection reset by peer
{"level":"error","service":"thumbnails","time":"2024-02-05T14:24:50-05:00","message":"resource info is missing checksum"}
{"level":"error","service":"thumbnails","time":"2024-02-05T14:24:50-05:00","message":"resource info is missing checksum"}
{"level":"error","service":"storage-users","pkg":"rgrpc","traceid":"264db4b1ed0924ecbb157896fd3c9ee9","error":"node.XattrsWithReader /Volumes/Store/ocis/storage/users/spaces/ac/b861ba-c024-40c3-8bdb-95f6f4041173/nodes: attribute not found","node":"","time":"2024-02-05T14:25:19-05:00","message":"error listing attributes"}
{"level":"error","service":"storage-users","pkg":"rgrpc","traceid":"264db4b1ed0924ecbb157896fd3c9ee9","error":"node.XattrsWithReader /Volumes/Store/ocis/storage/users/spaces/ac/b861ba-c024-40c3-8bdb-95f6f4041173/nodes: attribute not found","node":"marshaling error: json: unsupported value: encountered a cycle via *node.Node","time":"2024-02-05T14:25:19-05:00","message":"error listing grantees"}
{"level":"error","service":"storage-users","pkg":"rgrpc","traceid":"264db4b1ed0924ecbb157896fd3c9ee9","error":"node.XattrsWithReader /Volumes/Store/ocis/storage/users/spaces/ac/b861ba-c024-40c3-8bdb-95f6f4041173/nodes: attribute not found","node":"","time":"2024-02-05T14:25:19-05:00","message":"error reading permissions"}
{"level":"error","service":"storage-users","pkg":"rgrpc","traceid":"6ff09cd54850c97245488302bb6caf05","error":"error reading user index: stat /Volumes/Store/ocis/storage/users/indexes/by-user-id/3a5640ec-dcff-465f-bf3b-80f2a32dd046.mpk: no such file or directory","status":{"code":15,"message":"error listing spaces","trace":"6ff09cd54850c97245488302bb6caf05"},"filters":[{"type":4,"Term":{"SpaceType":"personal"}},{"type":6,"Term":{"User":{"opaque_id":"3a5640ec-dcff-465f-bf3b-80f2a32dd046"}}}],"time":"2024-02-05T14:26:23-05:00","message":"failed to list storage spaces"}
2024/02/05 14:30:00 http: TLS handshake error from xxx.xxx.xxx.xxx:52894: EOF
2024/02/05 14:30:00 http: TLS handshake error from xxx.xxx.xxx.xxx:52902: EOF
2024/02/05 14:30:00 http: TLS handshake error from xxx.xxx.xxx.xxx:52910: EOF
2024/02/05 14:30:01 http: TLS handshake error from xxx.xxx.xxx.xxx:52918: EOF
2024/02/05 14:30:01 http: TLS handshake error from xxx.xxx.xxx.xxx:52930: EOF
2024/02/05 14:30:01 http: TLS handshake error from xxx.xxx.xxx.xxx:52946: EOF
2024/02/05 14:30:01 http: TLS handshake error from xxx.xxx.xxx.xxx:52962: read tcp xxx.xxx.xxx.xxx:9200->xxx.xxx.xxx.xxx:52962: read: connection reset by peer
2024/02/05 14:30:01 http: TLS handshake error from xxx.xxx.xxx.xxx:52974: EOF
2024/02/05 14:30:01 http: TLS handshake error from xxx.xxx.xxx.xxx:52988: EOF
2024/02/05 14:30:01 http: TLS handshake error from xxx.xxx.xxx.xxx:52992: read tcp xxx.xxx.xxx.xxx:9200->xxx.xxx.xxx.xxx:52992: read: connection reset by peer
{"level":"error","service":"proxy","error":"failed to verify access token: token is expired by 31.807774s","authenticator":"oidc","path":"/ocs/v2.php/apps/notifications/api/v1/notifications/sse","time":"2024-02-05T14:30:20-05:00","message":"failed to authenticate the request"}
2024/02/05 14:39:56 http: proxy error: context canceled
{"level":"error","service":"frontend","pkg":"rhttp","traceid":"e48ced93802209b0edeb8e7276fa9256","request-id":"b89f28b4-77a5-420c-95e3-af5be523242d","error":"Patch \"http://localhost:9158/data/tus/398b3546-88b6-43c9-aff8-97fe10ffd4d4\": context canceled","time":"2024-02-05T14:39:56-05:00","message":"error doing PATCH request to data service"}
{"level":"error","service":"frontend","pkg":"rhttp","traceid":"e48ced93802209b0edeb8e7276fa9256","host":"127.0.0.1","method":"PATCH","uri":"/data/eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJyZXZhIiwiZXhwIjoxNzA3MjQ4MjM3LCJpYXQiOjE3MDcxNjE4MzcsInRhcmdldCI6Imh0dHA6Ly9sb2NhbGhvc3Q6OTE1OC9kYXRhL3R1cy8zOThiMzU0Ni04OGI2LTQzYzktYWZmOC05N2ZlMTBmZmQ0ZDQifQ.zkALZ0wuc4aBNuycSULhAE786BxhamaTnsHg1VfdvWQ","url":"/eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJyZXZhIiwiZXhwIjoxNzA3MjQ4MjM3LCJpYXQiOjE3MDcxNjE4MzcsInRhcmdldCI6Imh0dHA6Ly9sb2NhbGhvc3Q6OTE1OC9kYXRhL3R1cy8zOThiMzU0Ni04OGI2LTQzYzktYWZmOC05N2ZlMTBmZmQ0ZDQifQ.zkALZ0wuc4aBNuycSULhAE786BxhamaTnsHg1VfdvWQ","proto":"HTTP/1.1","status":500,"size":0,"start":"05/Feb/2024:14:39:52 -0500","end":"05/Feb/2024:14:39:56 -0500","time_ns":3960574052,"time":"2024-02-05T14:39:56-05:00","message":"http"}
{"level":"error","service":"storage-users","pkg":"rhttp","traceid":"1d794bcee68d0e2284541b9d69140fd1","host":"127.0.0.1","method":"PATCH","uri":"/data/tus/398b3546-88b6-43c9-aff8-97fe10ffd4d4","url":"/398b3546-88b6-43c9-aff8-97fe10ffd4d4","proto":"HTTP/1.1","status":500,"size":15,"start":"05/Feb/2024:14:39:52 -0500","end":"05/Feb/2024:14:39:56 -0500","time_ns":3963820864,"time":"2024-02-05T14:39:56-05:00","message":"http"}
2024/02/05 14:39:57 http: proxy error: context canceled
{"level":"error","service":"frontend","pkg":"rhttp","traceid":"eebe0fe5598bcef0bc5efdaebe856854","request-id":"5b97eada-af97-4d79-8684-1235e5f397d8","error":"Patch \"http://localhost:9158/data/tus/5ff1a834-9eea-4490-a981-4ec84f61c5b3\": context canceled","time":"2024-02-05T14:39:57-05:00","message":"error doing PATCH request to data service"}
{"level":"error","service":"frontend","pkg":"rhttp","traceid":"eebe0fe5598bcef0bc5efdaebe856854","host":"127.0.0.1","method":"PATCH","uri":"/data/eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJyZXZhIiwiZXhwIjoxNzA3MjQ4MjI2LCJpYXQiOjE3MDcxNjE4MjYsInRhcmdldCI6Imh0dHA6Ly9sb2NhbGhvc3Q6OTE1OC9kYXRhL3R1cy81ZmYxYTgzNC05ZWVhLTQ0OTAtYTk4MS00ZWM4NGY2MWM1YjMifQ.g8XZcOQEXuth3H4qg1NOdef8ovkWX6up-AWQYgtQL5o","url":"/eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJyZXZhIiwiZXhwIjoxNzA3MjQ4MjI2LCJpYXQiOjE3MDcxNjE4MjYsInRhcmdldCI6Imh0dHA6Ly9sb2NhbGhvc3Q6OTE1OC9kYXRhL3R1cy81ZmYxYTgzNC05ZWVhLTQ0OTAtYTk4MS00ZWM4NGY2MWM1YjMifQ.g8XZcOQEXuth3H4qg1NOdef8ovkWX6up-AWQYgtQL5o","proto":"HTTP/1.1","status":500,"size":0,"start":"05/Feb/2024:14:39:38 -0500","end":"05/Feb/2024:14:39:57 -0500","time_ns":18260660071,"time":"2024-02-05T14:39:57-05:00","message":"http"}
{"level":"error","service":"storage-users","pkg":"rhttp","traceid":"986c339923d177cb22b334a706eeb324","host":"127.0.0.1","method":"PATCH","uri":"/data/tus/5ff1a834-9eea-4490-a981-4ec84f61c5b3","url":"/5ff1a834-9eea-4490-a981-4ec84f61c5b3","proto":"HTTP/1.1","status":500,"size":15,"start":"05/Feb/2024:14:39:38 -0500","end":"05/Feb/2024:14:39:57 -0500","time_ns":18261625754,"time":"2024-02-05T14:39:57-05:00","message":"http"}
2024/02/05 14:39:57 http: proxy error: context canceled
{"level":"error","service":"frontend","pkg":"rhttp","traceid":"1272f400325721caa0642c2870fb5b73","request-id":"ede32c63-993f-4919-adce-e6040d1df35e","error":"Patch \"http://localhost:9158/data/tus/bb73ed81-200b-43b1-92fb-0dae39d15706\": context canceled","time":"2024-02-05T14:39:57-05:00","message":"error doing PATCH request to data service"}
{"level":"error","service":"frontend","pkg":"rhttp","traceid":"1272f400325721caa0642c2870fb5b73","host":"127.0.0.1","method":"PATCH","uri":"/data/eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJyZXZhIiwiZXhwIjoxNzA3MjQ4MjY5LCJpYXQiOjE3MDcxNjE4NjksInRhcmdldCI6Imh0dHA6Ly9sb2NhbGhvc3Q6OTE1OC9kYXRhL3R1cy9iYjczZWQ4MS0yMDBiLTQzYjEtOTJmYi0wZGFlMzlkMTU3MDYifQ.EViSdUKE2rqWVePIWrGN9yAnLEciCS4MgFEwUrvMgLY","url":"/eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJyZXZhIiwiZXhwIjoxNzA3MjQ4MjY5LCJpYXQiOjE3MDcxNjE4NjksInRhcmdldCI6Imh0dHA6Ly9sb2NhbGhvc3Q6OTE1OC9kYXRhL3R1cy9iYjczZWQ4MS0yMDBiLTQzYjEtOTJmYi0wZGFlMzlkMTU3MDYifQ.EViSdUKE2rqWVePIWrGN9yAnLEciCS4MgFEwUrvMgLY","proto":"HTTP/1.1","status":500,"size":0,"start":"05/Feb/2024:14:39:53 -0500","end":"05/Feb/2024:14:39:57 -0500","time_ns":3825928509,"time":"2024-02-05T14:39:57-05:00","message":"http"}
{"level":"error","service":"storage-users","pkg":"rhttp","traceid":"fb3feec51349572e632f0f3957330478","host":"127.0.0.1","method":"PATCH","uri":"/data/tus/bb73ed81-200b-43b1-92fb-0dae39d15706","url":"/bb73ed81-200b-43b1-92fb-0dae39d15706","proto":"HTTP/1.1","status":500,"size":15,"start":"05/Feb/2024:14:39:53 -0500","end":"05/Feb/2024:14:39:57 -0500","time_ns":3827335272,"time":"2024-02-05T14:39:57-05:00","message":"http"}
2024/02/05 14:39:58 http: proxy error: context canceled
{"level":"error","service":"frontend","pkg":"rhttp","traceid":"0ef9c676185803016671f5f0611d3aa9","request-id":"c04d578e-49e1-45c1-8f2b-4929934f7b23","error":"Patch \"http://localhost:9158/data/tus/524bb1bf-b03c-4063-b3bb-5ac038f25ba4\": context canceled","time":"2024-02-05T14:39:58-05:00","message":"error doing PATCH request to data service"}
{"level":"error","service":"frontend","pkg":"rhttp","traceid":"0ef9c676185803016671f5f0611d3aa9","host":"127.0.0.1","method":"PATCH","uri":"/data/eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJyZXZhIiwiZXhwIjoxNzA3MjQ4MTc3LCJpYXQiOjE3MDcxNjE3NzcsInRhcmdldCI6Imh0dHA6Ly9sb2NhbGhvc3Q6OTE1OC9kYXRhL3R1cy81MjRiYjFiZi1iMDNjLTQwNjMtYjNiYi01YWMwMzhmMjViYTQifQ.wzExhC8Wu7CEsRTmCV6d58o96LT0DMtw9DT6dqMNopk","url":"/eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJyZXZhIiwiZXhwIjoxNzA3MjQ4MTc3LCJpYXQiOjE3MDcxNjE3NzcsInRhcmdldCI6Imh0dHA6Ly9sb2NhbGhvc3Q6OTE1OC9kYXRhL3R1cy81MjRiYjFiZi1iMDNjLTQwNjMtYjNiYi01YWMwMzhmMjViYTQifQ.wzExhC8Wu7CEsRTmCV6d58o96LT0DMtw9DT6dqMNopk","proto":"HTTP/1.1","status":500,"size":0,"start":"05/Feb/2024:14:39:50 -0500","end":"05/Feb/2024:14:39:58 -0500","time_ns":7236473712,"time":"2024-02-05T14:39:58-05:00","message":"http"}
{"level":"error","service":"storage-users","pkg":"rhttp","traceid":"676cb6a935af7662476d01cc296c25d7","host":"127.0.0.1","method":"PATCH","uri":"/data/tus/524bb1bf-b03c-4063-b3bb-5ac038f25ba4","url":"/524bb1bf-b03c-4063-b3bb-5ac038f25ba4","proto":"HTTP/1.1","status":500,"size":15,"start":"05/Feb/2024:14:39:50 -0500","end":"05/Feb/2024:14:39:58 -0500","time_ns":7236351195,"time":"2024-02-05T14:39:58-05:00","message":"http"}
{"level":"error","service":"thumbnails","time":"2024-02-05T14:40:03-05:00","message":"resource info is missing checksum"}
{"level":"error","service":"thumbnails","time":"2024-02-05T14:40:03-05:00","message":"resource info is missing checksum"}
{"level":"error","service":"storage-users","pkg":"rgrpc","traceid":"dcb0df1ffecf2bab0fa75897cb665da4","error":"stat /Volumes/Store/ocis/storage/users/spaces/ac/b861ba-c024-40c3-8bdb-95f6f4041173/nodes/b2/d8/cc/c7/-ff65-47ef-9e3a-8f9daa956418: no such file or directory","node":"b2d8ccc7-ff65-47ef-9e3a-8f9daa956418","time":"2024-02-05T14:40:30-05:00","message":"error listing attributes"}
{"level":"error","service":"storage-users","pkg":"rgrpc","traceid":"dcb0df1ffecf2bab0fa75897cb665da4","error":"stat /Volumes/Store/ocis/storage/users/spaces/ac/b861ba-c024-40c3-8bdb-95f6f4041173/nodes/b2/d8/cc/c7/-ff65-47ef-9e3a-8f9daa956418: no such file or directory","node":"marshaling error: json: unsupported value: encountered a cycle via *node.Node","time":"2024-02-05T14:40:30-05:00","message":"error listing grantees"}
{"level":"error","service":"storage-users","pkg":"rgrpc","traceid":"dcb0df1ffecf2bab0fa75897cb665da4","error":"stat /Volumes/Store/ocis/storage/users/spaces/ac/b861ba-c024-40c3-8bdb-95f6f4041173/nodes/b2/d8/cc/c7/-ff65-47ef-9e3a-8f9daa956418: no such file or directory","node":"b2d8ccc7-ff65-47ef-9e3a-8f9daa956418","time":"2024-02-05T14:40:30-05:00","message":"error reading permissions"}
{"level":"error","service":"storage-users","pkg":"rgrpc","traceid":"dcb0df1ffecf2bab0fa75897cb665da4","error":"stat /Volumes/Store/ocis/storage/users/spaces/ac/b861ba-c024-40c3-8bdb-95f6f4041173/nodes/bc/16/ff/d2/-f43e-4b89-89d9-36e7919cfab7: no such file or directory","node":"bc16ffd2-f43e-4b89-89d9-36e7919cfab7","time":"2024-02-05T14:40:30-05:00","message":"error listing attributes"}
{"level":"error","service":"storage-users","pkg":"rgrpc","traceid":"dcb0df1ffecf2bab0fa75897cb665da4","error":"stat /Volumes/Store/ocis/storage/users/spaces/ac/b861ba-c024-40c3-8bdb-95f6f4041173/nodes/bc/16/ff/d2/-f43e-4b89-89d9-36e7919cfab7: no such file or directory","node":"marshaling error: json: unsupported value: encountered a cycle via *node.Node","time":"2024-02-05T14:40:30-05:00","message":"error listing grantees"}
{"level":"error","service":"storage-users","pkg":"rgrpc","traceid":"dcb0df1ffecf2bab0fa75897cb665da4","error":"stat /Volumes/Store/ocis/storage/users/spaces/ac/b861ba-c024-40c3-8bdb-95f6f4041173/nodes/bc/16/ff/d2/-f43e-4b89-89d9-36e7919cfab7: no such file or directory","node":"bc16ffd2-f43e-4b89-89d9-36e7919cfab7","time":"2024-02-05T14:40:30-05:00","message":"error reading permissions"}
{"level":"error","service":"storage-users","pkg":"rgrpc","traceid":"c702844caa02091104ac8d8bbf6bf9ab","error":"node.XattrsWithReader /Volumes/Store/ocis/storage/users/spaces/ac/b861ba-c024-40c3-8bdb-95f6f4041173/nodes: attribute not found","node":"","time":"2024-02-05T14:40:55-05:00","message":"error listing attributes"}
{"level":"error","service":"storage-users","pkg":"rgrpc","traceid":"c702844caa02091104ac8d8bbf6bf9ab","error":"node.XattrsWithReader /Volumes/Store/ocis/storage/users/spaces/ac/b861ba-c024-40c3-8bdb-95f6f4041173/nodes: attribute not found","node":"marshaling error: json: unsupported value: encountered a cycle via *node.Node","time":"2024-02-05T14:40:55-05:00","message":"error listing grantees"}
{"level":"error","service":"storage-users","pkg":"rgrpc","traceid":"c702844caa02091104ac8d8bbf6bf9ab","error":"node.XattrsWithReader /Volumes/Store/ocis/storage/users/spaces/ac/b861ba-c024-40c3-8bdb-95f6f4041173/nodes: attribute not found","node":"","time":"2024-02-05T14:40:55-05:00","message":"error reading permissions"}
{"level":"error","pid":97591,"pid":97591,"path":"/Volumes/Store/ocis/storage/users/spaces/ac/b861ba-c024-40c3-8bdb-95f6f4041173/nodes/47/72/e2/55/-0ced-4671-b2e0-e60a600b3699","nodeid":"4772e255-0ced-4671-b2e0-e60a600b3699","attrs":{},"messagepack":"","time":"2024-02-05T14:44:20-05:00","caller":"github.com/cs3org/reva/v2@v2.18.1-0.20240126141248-c9e4a3bcd0da/pkg/storage/utils/decomposedfs/upload/upload.go:304","message":"missing parent id"}
{"level":"error","pid":97591,"pid":97591,"session":"524bb1bf-b03c-4063-b3bb-5ac038f25ba4","error":"internal error: Missing parent ID on node","time":"2024-02-05T14:44:20-05:00","caller":"github.com/cs3org/reva/v2@v2.18.1-0.20240126141248-c9e4a3bcd0da/pkg/storage/utils/decomposedfs/upload/store.go:161","message":"getting node from session failed"}
{"level":"error","service":"storage-users","pkg":"rhttp","traceid":"3b219e72a8ff5927546eaba0ccf3ae7e","host":"127.0.0.1","method":"PATCH","uri":"/data/tus/524bb1bf-b03c-4063-b3bb-5ac038f25ba4","url":"/524bb1bf-b03c-4063-b3bb-5ac038f25ba4","proto":"HTTP/1.1","status":500,"size":273,"start":"05/Feb/2024:14:44:10 -0500","end":"05/Feb/2024:14:44:20 -0500","time_ns":9527198450,"time":"2024-02-05T14:44:20-05:00","message":"http"}
{"level":"error","service":"frontend","pkg":"rhttp","traceid":"c2a9150ad9d5418d1c0216d4e63d4c68","host":"127.0.0.1","method":"PATCH","uri":"/data/eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJyZXZhIiwiZXhwIjoxNzA3MjQ4MTc3LCJpYXQiOjE3MDcxNjE3NzcsInRhcmdldCI6Imh0dHA6Ly9sb2NhbGhvc3Q6OTE1OC9kYXRhL3R1cy81MjRiYjFiZi1iMDNjLTQwNjMtYjNiYi01YWMwMzhmMjViYTQifQ.wzExhC8Wu7CEsRTmCV6d58o96LT0DMtw9DT6dqMNopk","url":"/eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJyZXZhIiwiZXhwIjoxNzA3MjQ4MTc3LCJpYXQiOjE3MDcxNjE3NzcsInRhcmdldCI6Imh0dHA6Ly9sb2NhbGhvc3Q6OTE1OC9kYXRhL3R1cy81MjRiYjFiZi1iMDNjLTQwNjMtYjNiYi01YWMwMzhmMjViYTQifQ.wzExhC8Wu7CEsRTmCV6d58o96LT0DMtw9DT6dqMNopk","proto":"HTTP/1.1","status":500,"size":0,"start":"05/Feb/2024:14:44:10 -0500","end":"05/Feb/2024:14:44:20 -0500","time_ns":9527621506,"time":"2024-02-05T14:44:20-05:00","message":"http"}
{"level":"error","pid":97591,"pid":97591,"path":"/Volumes/Store/ocis/storage/users/spaces/ac/b861ba-c024-40c3-8bdb-95f6f4041173/nodes/86/27/63/e8/-a392-4af6-a48d-37dfec93d075","nodeid":"862763e8-a392-4af6-a48d-37dfec93d075","attrs":{},"messagepack":"","time":"2024-02-05T14:44:59-05:00","caller":"github.com/cs3org/reva/v2@v2.18.1-0.20240126141248-c9e4a3bcd0da/pkg/storage/utils/decomposedfs/upload/upload.go:304","message":"missing parent id"}
{"level":"error","pid":97591,"pid":97591,"session":"398b3546-88b6-43c9-aff8-97fe10ffd4d4","error":"internal error: Missing parent ID on node","time":"2024-02-05T14:44:59-05:00","caller":"github.com/cs3org/reva/v2@v2.18.1-0.20240126141248-c9e4a3bcd0da/pkg/storage/utils/decomposedfs/upload/store.go:161","message":"getting node from session failed"}
{"level":"error","service":"storage-users","pkg":"rhttp","traceid":"2e9fe36df3d50e8d795dc7e916485f01","host":"127.0.0.1","method":"PATCH","uri":"/data/tus/398b3546-88b6-43c9-aff8-97fe10ffd4d4","url":"/398b3546-88b6-43c9-aff8-97fe10ffd4d4","proto":"HTTP/1.1","status":500,"size":273,"start":"05/Feb/2024:14:44:52 -0500","end":"05/Feb/2024:14:44:59 -0500","time_ns":7554077114,"time":"2024-02-05T14:44:59-05:00","message":"http"}
{"level":"error","service":"frontend","pkg":"rhttp","traceid":"5d96d4db2dc1f0581cbbb104307cab13","host":"127.0.0.1","method":"PATCH","uri":"/data/eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJyZXZhIiwiZXhwIjoxNzA3MjQ4MjM3LCJpYXQiOjE3MDcxNjE4MzcsInRhcmdldCI6Imh0dHA6Ly9sb2NhbGhvc3Q6OTE1OC9kYXRhL3R1cy8zOThiMzU0Ni04OGI2LTQzYzktYWZmOC05N2ZlMTBmZmQ0ZDQifQ.zkALZ0wuc4aBNuycSULhAE786BxhamaTnsHg1VfdvWQ","url":"/eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJyZXZhIiwiZXhwIjoxNzA3MjQ4MjM3LCJpYXQiOjE3MDcxNjE4MzcsInRhcmdldCI6Imh0dHA6Ly9sb2NhbGhvc3Q6OTE1OC9kYXRhL3R1cy8zOThiMzU0Ni04OGI2LTQzYzktYWZmOC05N2ZlMTBmZmQ0ZDQifQ.zkALZ0wuc4aBNuycSULhAE786BxhamaTnsHg1VfdvWQ","proto":"HTTP/1.1","status":500,"size":0,"start":"05/Feb/2024:14:44:52 -0500","end":"05/Feb/2024:14:44:59 -0500","time_ns":7554446474,"time":"2024-02-05T14:44:59-05:00","message":"http"}
{"level":"error","service":"proxy","error":"failed to verify access token: token is expired by 2.667337s","authenticator":"oidc","path":"/remote.php/dav/spaces/dc0b96eb-74ac-49aa-bbf4-fe3415810fd7$acb861ba-c024-40c3-8bdb-95f6f4041173/Raw files/2024_02_05_Michael Kirkham_RAF_01","time":"2024-02-05T14:45:00-05:00","message":"failed to authenticate the request"}
{"level":"error","pid":97591,"pid":97591,"path":"/Volumes/Store/ocis/storage/users/spaces/ac/b861ba-c024-40c3-8bdb-95f6f4041173/nodes/08/96/b8/3d/-51bc-465a-bf90-b06582ecb9a9","nodeid":"0896b83d-51bc-465a-bf90-b06582ecb9a9","attrs":{},"messagepack":"","time":"2024-02-05T14:45:01-05:00","caller":"github.com/cs3org/reva/v2@v2.18.1-0.20240126141248-c9e4a3bcd0da/pkg/storage/utils/decomposedfs/upload/upload.go:304","message":"missing parent id"}
{"level":"error","pid":97591,"pid":97591,"session":"a8c9d0a6-eab9-42e1-87f7-92e53a93ced0","error":"internal error: Missing parent ID on node","time":"2024-02-05T14:45:01-05:00","caller":"github.com/cs3org/reva/v2@v2.18.1-0.20240126141248-c9e4a3bcd0da/pkg/storage/utils/decomposedfs/upload/store.go:161","message":"getting node from session failed"}
{"level":"error","service":"storage-users","pkg":"rhttp","traceid":"ae1a828b7efb811584c9c30964a4240f","host":"127.0.0.1","method":"PATCH","uri":"/data/tus/a8c9d0a6-eab9-42e1-87f7-92e53a93ced0","url":"/a8c9d0a6-eab9-42e1-87f7-92e53a93ced0","proto":"HTTP/1.1","status":500,"size":273,"start":"05/Feb/2024:14:44:54 -0500","end":"05/Feb/2024:14:45:01 -0500","time_ns":6518425257,"time":"2024-02-05T14:45:01-05:00","message":"http"}
{"level":"error","service":"frontend","pkg":"rhttp","traceid":"f274c180142f77483759ce010d484f55","host":"127.0.0.1","method":"PATCH","uri":"/data/eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJyZXZhIiwiZXhwIjoxNzA3MjQ4MjI1LCJpYXQiOjE3MDcxNjE4MjUsInRhcmdldCI6Imh0dHA6Ly9sb2NhbGhvc3Q6OTE1OC9kYXRhL3R1cy9hOGM5ZDBhNi1lYWI5LTQyZTEtODdmNy05MmU1M2E5M2NlZDAifQ.eMWcla1K-Nlq-UeqgYlZxQnItGJTj41Hn5uLYAYkOLs","url":"/eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJyZXZhIiwiZXhwIjoxNzA3MjQ4MjI1LCJpYXQiOjE3MDcxNjE4MjUsInRhcmdldCI6Imh0dHA6Ly9sb2NhbGhvc3Q6OTE1OC9kYXRhL3R1cy9hOGM5ZDBhNi1lYWI5LTQyZTEtODdmNy05MmU1M2E5M2NlZDAifQ.eMWcla1K-Nlq-UeqgYlZxQnItGJTj41Hn5uLYAYkOLs","proto":"HTTP/1.1","status":500,"size":0,"start":"05/Feb/2024:14:44:54 -0500","end":"05/Feb/2024:14:45:01 -0500","time_ns":6518822599,"time":"2024-02-05T14:45:01-05:00","message":"http"}
{"level":"error","service":"proxy","error":"failed to verify access token: token is expired by 4.461757s","authenticator":"oidc","path":"/remote.php/dav/spaces/dc0b96eb-74ac-49aa-bbf4-fe3415810fd7$acb861ba-c024-40c3-8bdb-95f6f4041173/Raw files/2024_02_05_Michael Kirkham_RAF_01","time":"2024-02-05T14:45:02-05:00","message":"failed to authenticate the request"}
{"level":"error","pid":97591,"pid":97591,"path":"/Volumes/Store/ocis/storage/users/spaces/ac/b861ba-c024-40c3-8bdb-95f6f4041173/nodes/3c/47/18/ec/-a6b0-4c9b-a4f1-3eac67c60bc4","nodeid":"3c4718ec-a6b0-4c9b-a4f1-3eac67c60bc4","attrs":{},"messagepack":"","time":"2024-02-05T14:45:24-05:00","caller":"github.com/cs3org/reva/v2@v2.18.1-0.20240126141248-c9e4a3bcd0da/pkg/storage/utils/decomposedfs/upload/upload.go:304","message":"missing parent id"}
{"level":"error","pid":97591,"pid":97591,"session":"5ff1a834-9eea-4490-a981-4ec84f61c5b3","error":"internal error: Missing parent ID on node","time":"2024-02-05T14:45:24-05:00","caller":"github.com/cs3org/reva/v2@v2.18.1-0.20240126141248-c9e4a3bcd0da/pkg/storage/utils/decomposedfs/upload/store.go:161","message":"getting node from session failed"}
{"level":"error","service":"storage-users","pkg":"rhttp","traceid":"814129a33bb9f833ebeb11620132afdb","host":"127.0.0.1","method":"PATCH","uri":"/data/tus/5ff1a834-9eea-4490-a981-4ec84f61c5b3","url":"/5ff1a834-9eea-4490-a981-4ec84f61c5b3","proto":"HTTP/1.1","status":500,"size":273,"start":"05/Feb/2024:14:45:23 -0500","end":"05/Feb/2024:14:45:24 -0500","time_ns":612182206,"time":"2024-02-05T14:45:24-05:00","message":"http"}
{"level":"error","service":"frontend","pkg":"rhttp","traceid":"ca4aad354baaf8467fa6003ec5936a87","host":"127.0.0.1","method":"PATCH","uri":"/data/eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJyZXZhIiwiZXhwIjoxNzA3MjQ4MjI2LCJpYXQiOjE3MDcxNjE4MjYsInRhcmdldCI6Imh0dHA6Ly9sb2NhbGhvc3Q6OTE1OC9kYXRhL3R1cy81ZmYxYTgzNC05ZWVhLTQ0OTAtYTk4MS00ZWM4NGY2MWM1YjMifQ.g8XZcOQEXuth3H4qg1NOdef8ovkWX6up-AWQYgtQL5o","url":"/eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJyZXZhIiwiZXhwIjoxNzA3MjQ4MjI2LCJpYXQiOjE3MDcxNjE4MjYsInRhcmdldCI6Imh0dHA6Ly9sb2NhbGhvc3Q6OTE1OC9kYXRhL3R1cy81ZmYxYTgzNC05ZWVhLTQ0OTAtYTk4MS00ZWM4NGY2MWM1YjMifQ.g8XZcOQEXuth3H4qg1NOdef8ovkWX6up-AWQYgtQL5o","proto":"HTTP/1.1","status":500,"size":0,"start":"05/Feb/2024:14:45:23 -0500","end":"05/Feb/2024:14:45:24 -0500","time_ns":612584128,"time":"2024-02-05T14:45:24-05:00","message":"http"}
{"level":"error","service":"proxy","error":"failed to verify access token: token is expired by 32.445491s","authenticator":"oidc","path":"/remote.php/dav/spaces/dc0b96eb-74ac-49aa-bbf4-fe3415810fd7$acb861ba-c024-40c3-8bdb-95f6f4041173/Raw files/2024_02_05_Michael Kirkham_RAF_01","time":"2024-02-05T14:45:30-05:00","message":"failed to authenticate the request"}
{"level":"error","service":"proxy","error":"failed to verify access token: token is expired by 32.446618s","authenticator":"oidc","path":"/remote.php/dav/spaces/dc0b96eb-74ac-49aa-bbf4-fe3415810fd7$acb861ba-c024-40c3-8bdb-95f6f4041173/Raw files/2024_02_05_Michael Kirkham_RAF_01","time":"2024-02-05T14:45:30-05:00","message":"failed to authenticate the request"}
{"level":"error","pid":97591,"pid":97591,"path":"/Volumes/Store/ocis/storage/users/spaces/ac/b861ba-c024-40c3-8bdb-95f6f4041173/nodes/11/93/35/48/-236b-448d-9757-eab46182a185","nodeid":"11933548-236b-448d-9757-eab46182a185","attrs":{},"messagepack":"","time":"2024-02-05T14:47:09-05:00","caller":"github.com/cs3org/reva/v2@v2.18.1-0.20240126141248-c9e4a3bcd0da/pkg/storage/utils/decomposedfs/upload/upload.go:304","message":"missing parent id"}
{"level":"error","pid":97591,"pid":97591,"session":"bb73ed81-200b-43b1-92fb-0dae39d15706","error":"internal error: Missing parent ID on node","time":"2024-02-05T14:47:09-05:00","caller":"github.com/cs3org/reva/v2@v2.18.1-0.20240126141248-c9e4a3bcd0da/pkg/storage/utils/decomposedfs/upload/store.go:161","message":"getting node from session failed"}
{"level":"error","service":"storage-users","pkg":"rhttp","traceid":"6ec6d9b76ba36d40691055cdfc94d59e","host":"127.0.0.1","method":"PATCH","uri":"/data/tus/bb73ed81-200b-43b1-92fb-0dae39d15706","url":"/bb73ed81-200b-43b1-92fb-0dae39d15706","proto":"HTTP/1.1","status":500,"size":273,"start":"05/Feb/2024:14:46:01 -0500","end":"05/Feb/2024:14:47:09 -0500","time_ns":68309458927,"time":"2024-02-05T14:47:09-05:00","message":"http"}
{"level":"error","service":"frontend","pkg":"rhttp","traceid":"54e79e535e37c38fe5e434e7e055e742","host":"127.0.0.1","method":"PATCH","uri":"/data/eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJyZXZhIiwiZXhwIjoxNzA3MjQ4MjY5LCJpYXQiOjE3MDcxNjE4NjksInRhcmdldCI6Imh0dHA6Ly9sb2NhbGhvc3Q6OTE1OC9kYXRhL3R1cy9iYjczZWQ4MS0yMDBiLTQzYjEtOTJmYi0wZGFlMzlkMTU3MDYifQ.EViSdUKE2rqWVePIWrGN9yAnLEciCS4MgFEwUrvMgLY","url":"/eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJyZXZhIiwiZXhwIjoxNzA3MjQ4MjY5LCJpYXQiOjE3MDcxNjE4NjksInRhcmdldCI6Imh0dHA6Ly9sb2NhbGhvc3Q6OTE1OC9kYXRhL3R1cy9iYjczZWQ4MS0yMDBiLTQzYjEtOTJmYi0wZGFlMzlkMTU3MDYifQ.EViSdUKE2rqWVePIWrGN9yAnLEciCS4MgFEwUrvMgLY","proto":"HTTP/1.1","status":500,"size":0,"start":"05/Feb/2024:14:46:01 -0500","end":"05/Feb/2024:14:47:09 -0500","time_ns":68309893960,"time":"2024-02-05T14:47:09-05:00","message":"http"}
{"level":"error","service":"proxy","error":"failed to verify access token: token is expired by 4.800648s","authenticator":"oidc","path":"/ocs/v2.php/apps/notifications/api/v1/notifications/sse","time":"2024-02-05T15:05:31-05:00","message":"failed to authenticate the request"}

Normally when large file uploads fail, I'd investigate Apache and PHP file and memory limits, but I don't believe those apply here. I thought permissions might be an issue-the store is located on an external disk and I did not set up a dedicated "ocis" user as the deployment instructions specify. But why would some uploads work while others fail? I am stumped!

I'd be grateful for any advice, and would like to extend a huge "thanks" to the devs who make OC so fantastic.

micbar commented 7 months ago

I must admin, setting up OIDC is sometimes a bit hard.

Can your ocis reach the idp from inside your host?

You should be able to do a curl to https://ocis.server.com/.well-known/openid-configuration

micbar commented 7 months ago

In your logs, I also see a lot of errors which indicate that ocis could not read from the filesystem. Maybe a permissions problem?

prohtex commented 7 months ago

In your logs, I also see a lot of errors which indicate that ocis could not read from the filesystem. Maybe a permissions problem?

The only way I could get the binary to run as a launchctl service (macOS daemon) was to run as root. The ocis directory permissions are as follows:

user$ ls -lah ocis
total 32
drwxr-xr-x  12 user  staff   408B Feb  4 13:51 .
drwxrwxr-x  11 user  staff   442B Feb  5 23:56 ..
-rw-r--r--@  1 user  staff   8.0K Feb  4 13:51 .DS_Store
drwx------   5 user  staff   170B Feb  4 04:27 idm
drwx------   5 user  staff   170B Feb  4 04:27 idp
drwxr-x---   4 user  staff   136B Feb  4 13:51 nats
drwx------   4 user  staff   136B Feb  4 04:27 proxy
drwx------   4 user  staff   136B Feb  4 13:51 search
drwx------   6 user  staff   204B Feb  4 13:51 storage
drwx------   5 user  staff   170B Feb  4 15:17 store
drwx------   4 user  staff   136B Feb  4 13:51 thumbnails
drwxr-x---   3 user  staff   102B Feb  4 04:43 web

You can see macOS pollutes the directory tree with those cursed .DS_Store files. This used to be an issue for OC10 any time I would browse the data directory.

prohtex commented 7 months ago

I must admin, setting up OIDC is sometimes a bit hard.

Can your ocis reach the idp from inside your host?

You should be able to do a curl to https://ocis.server.com/.well-known/openid-configuration

Yes, it can.

prohtex commented 7 months ago

I must admin, setting up OIDC is sometimes a bit hard.

Can your ocis reach the idp from inside your host?

You should be able to do a curl to https://ocis.server.com/.well-known/openid-configuration

Hi @micbar can you provide more information about how I might change the token expiry? I tried this but it had no effect: IDP_ACCESS_TOKEN_EXPIRATION=2592000 IDP_ID_TOKEN_EXPIRATION=2592000

Here is my test procedure:

  1. Make a new directory. Add a copy of ubuntu-22.04.3-live-server-amd64.iso. Duplicate 8 times until directory is 17GB in size
  2. Log in and drag directory to browser window
  3. Upload fails when tokens expire

I can reproduce this issue in every test environment I try, including OCIS 4.0.6, OCIS latest, ocis_wopi, Darwin binary, Ubuntu inside VM, everything, including the OCIS continual deployment test server as documented in owncloud/web#10474. Is there some extra process to configure OIDC that is undocumented or am I the only one trying to upload large files to OCIS?

Thank you for your help!

appiekap653 commented 4 months ago

same problem here, doesn't matter if I use android client, web client, rclone, everything above 20mb is causing the same error you have

micbar commented 3 months ago

guys 😄 we are using our own software too 😏 and we have a ton of tests running. Large file uploads are working on our instances.

Please check https://owncloud.dev/ocis/deployment/continuous_deployment/

Can you please post the errors or a screenshot of the network tab of the browser dev tools?

I uploaded an example large file upload. You can see in my example that the TUS upload creates the upload with a POST request and executes PATCH request to the /data/<uploadID> endpoint.

I would suggest, that your problem is somewhere in that area.

Example

screenshot-upload
micbar commented 3 months ago

@prohtex @appiekap653

We have the linked web issue. This is indeed not nice. I must admit that i didn't run into that in real life or in End2End tests. But i always have my browser tab focused. Same in the Tests.

@appiekap653 I am a bit puzzled with that reference to the other clients.

@jesmrec Can you clarify android?

rclone

@appiekap653 How do you connect with rclone? Rclone needs to refresh access tokens too.

appiekap653 commented 3 months ago

@prohtex @appiekap653

We have the linked web issue. This is indeed not nice. I must admit that i didn't run into that in real life or in End2End tests. But i always have my browser tab focused. Same in the Tests.

@appiekap653 I am a bit puzzled with that reference to the other clients.

@jesmrec Can you clarify android?

rclone

@appiekap653 How do you connect with rclone? Rclone needs to refresh access tokens too.

I connect with RClone following the inductions from this link

https://owncloud.dev/clients/rclone/webdav-sync-oidc/

Ocis is setup with all basic settings following the deployment example. Only thing that is configured differently is the Idp provider. I'm using an external provider (Authentik). In Authentik I have set the access token to be valid for 24 hours until it needs to be refreshed. Despite the 24 hours duration I still get errors with Rclone, Android and web clients when uploading any type of file greater than 20mb

Rclone gives this message:

DEBUG : webdav root '': Bearer token expired: 401 
Unauthorized ERROR : rc: "operations/uploadfile": error: Bad Gateway: 502 Bad Gateway

It looks like it is also related and likewise to:

https://github.com/owncloud/web/issues/10474

micbar commented 3 months ago

@appiekap653 I doubt that the issue with web is related. Web has an issue with tab throttling which leads to timing problems during the token refresh.