nextcloud / richdocuments

📑 Collabora Online for Nextcloud
https://nextcloud.com/collaboraonline
350 stars 115 forks source link

[Bug]: PHP unlink error, no such file: `unlink(/var/www/nextcloud/data/appdata_[...]/richdocuments/remoteData/capabilities` #3912

Open jameskimmel opened 4 weeks ago

jameskimmel commented 4 weeks ago

⚠️ This issue respects the following points: ⚠️

Bug description

As discussed here: https://help.nextcloud.com/t/php-error-unlink-var-www-nextcloud-data-appdata-ocgfs89mpg4c-richdocuments-remotedata-capabilities-no-such-file-or-directory-at-var-www-nextcloud-lib-private-files-storage-local-php-348/198537

the system logs PHP errors like these:

[PHP] Error: unlink(/var/www/nextcloud/data/appdata_ocgfs89mpg4c/richdocuments/remoteData/capabilities): No such file or directory at /var/www/nextcloud/lib/private/Files/Storage/Local.php#348
    GET /ocs/v2.php/apps/notifications/api/v2/notifications?format=json

Steps to reproduce

Not clear. But all affected users seem to use Collabora Online - Built-in CODE Server

Expected behavior

No errors under the logging page.

Installation method

Community Manual installation with Archive

Nextcloud Server version

28

Operating system

Debian/Ubuntu

PHP engine version

PHP 8.1

Web server

Nginx

Database engine version

MariaDB

Is this bug present after an update or on a fresh install?

Upgraded to a MAJOR version (ex. 28 to 29)

Are you using the Nextcloud Server Encryption module?

None

What user-backends are you using?

Nextcloud Logs

{"reqId":"O736PgfFCb34EnaHt59Q","level":3,"time":"2024-08-13T16:50:10+00:00","remoteAddr":"redact","user":"user","app":"PHP","method":"GET","url":"/index.phps/api/v1/stats","message":"unlink(/mnt/nextcloud/data/appdata_ocyao8xfftvv/richdocuments/remoteData/discovery): No such file or directory at /var/www/nextcloud/lib/private/Files/Storage/Local.php#348","userAgent":"Mozilla/5.0 (X11; Linux x86_64; rv:127.0) Gecko/20100101 Firefox/127.0","version":"29.0.4.1","data":{"app":"PHP"},"id":"66bcace1b6880"}
rakekniven commented 3 weeks ago

Confirm this issue since update from v29.0.3 to v29.0.4 Running Ubuntu 22.04, PHP 8.1 and PostgreSQL. (No docker or snap)

scubamuc commented 3 weeks ago

The Nextcloud snap team tests and documents recommended default apps. Our documentation for CODE & Nextcloud Office configuration is also part of the default fresh install snap testing. These tests are largely automated.

This issue has not appeared on fresh install tests, but does occur upon upgrading from 29.0.3 to 29.0.4. Thus I'm confirming this issue in Nextcloud snap 29.0.4snap2 on my personal productive instance.

grafik

[PHP] Fehler: unlink(/media/data/appdata_ocebz5f5f1qq/richdocuments/remoteData/capabilities): No such file or directory at /snap/nextcloud/43538/htdocs/lib/private/Files/Storage/Local.php#348 ....
    GET /ocs/v2.php/apps/user_status/api/v1/user_status?format=json
joshtrichards commented 3 weeks ago

Been seeing various reports of this, on the community forum, for the past month or two as well:

https://help.nextcloud.com/search?q=Unlink%20richdocuments%20order%3Alikes

KwisatzJim commented 3 weeks ago

Nextcloud version (eg, 29.0.5): 29.0.4 Operating system and version (eg, Ubuntu 24.04): Pop_OS 22.04 Apache or nginx version (eg, Apache 2.4.25): Apache 2.4.52 PHP version (eg, 8.3): 8.3.9

The issue you are facing:

[PHP] Error: unlink(/var/www/nextcloud/data/appdata_ocgfs89mpg4c/richdocuments/remoteData/capabilities): No such file or directory at /var/www/nextcloud/lib/private/Files/Storage/Local.php#348 GET /ocs/v2.php/apps/notifications/api/v2/notifications?format=json

I’m getting multiple entries in logs for this error since version nc28. Entries show IP of 2 different computers.

/var/www/nextcloud/data/appdata_ocgfs89mpg4c/richdocuments/remoteData/capabilities and /var/www/nextcloud/lib/private/Files/Storage/Local.php do exist and appear to be valid.

I’ve tried clearing browser cache on both computers that get the error.

I’ve run the following at various times to try to find/fix the error: occ maintenance:repair occ files:cleanup occ files:repair-tree occ files:scan jim occ files:scan-app-data occ check occ setupchecks

Is this the first time you’ve seen this error? (Y/N): N

Steps to replicate it:

check logs The output of your Nextcloud log in Admin > Logging:

[PHP] Error: unlink(/var/www/nextcloud/data/appdata_ocgfs89mpg4c/richdocuments/remoteData/capabilities): No such file or directory at /var/www/nextcloud/lib/private/Files/Storage/Local.php#348 GET /ocs/v2.php/apps/notifications/api/v2/notifications?format=json The output of your config.php file in /path/to/nextcloud (make sure you remove any identifiable information!):

<?php $CONFIG = array ( 'instanceid' => 'XXXXXXXXXXX', 'passwordsalt' => 'XXXXXXXXXXX', 'secret' => 'XXXXXXXXXXX', 'trusted_domains' => array ( 0 => 'XXXXXXXXXXX', 1 => 'XXXXXXXXXXX', ), 'memcache.local' => '\OC\Memcache\APCu', 'memcache.distributed' => '\OC\Memcache\Redis', 'memcache.locking' => '\OC\Memcache\Redis', 'redis' => array ( 'host' => 'localhost', 'port' => 6379, 'timeout' => 1.5, 'readtimeout' => 1.5, 'dbindex' => 0, ), 'datadirectory' => '/var/www/nextcloud/data', 'dbtype' => 'mysql', 'version' => '29.0.4.1', 'overwrite.cli.url' => 'https://localhost', 'dbname' => 'nextcloud', 'dbhost' => 'localhost', 'dbport' => '', 'dbtableprefix' => 'oc', 'mysql.utf8mb4' => true, 'dbuser' => 'nextcloud', 'dbpassword' => 'XXXXXXXXXXX', 'installed' => true, 'memories.db.triggers.fcu' => true, 'memories.exiftool' => '/var/www/nextcloud/apps/memories/bin-ext/exiftool-amd64-glibc', 'memories.vod.path' => '/var/www/nextcloud/apps/memories/bin-ext/go-vod-amd64', 'memories.vod.ffmpeg' => '/usr/bin/ffmpeg', 'memories.vod.ffprobe' => '/usr/bin/ffprobe', 'app_install_overwrite' => array ( 0 => 'news', ), 'htaccess.RewriteBase' => '/', 'default_phone_region' => 'US', 'maintenance_window_start' => 1, 'default_locale' => 'en_US', 'mail_from_address' => 'XXXXXXXXXXX', 'mail_smtpmode' => 'smtp', 'mail_sendmailmode' => 'smtp', 'mail_domain' => 'XXXXXXXXXXX', 'mail_smtphost' => 'XXXXXXXXXXX', 'mail_smtpport' => 'XXXXXXXXXXX', 'mail_smtpauth' => '1', 'mail_smtpname' => 'XXXXXXXXXXX', 'mail_smtppassword' => 'XXXXXXXXXXX', 'maintenance' => false, 'memories.gis_type' => 1, 'overwriteprotocol' => 'https', 'trusted_proxies' => array ( 0 => '127.0.0.1', 1 => '::1', ), 'enabledPreviewProviders' => array ( 0 => 'OC\Preview\Image', 1 => 'OC\Preview\HEIC', 2 => 'OC\Preview\TIFF', 3 => 'OC\Preview\Movie', ), 'preview_max_x' => 1024, 'preview_max_y' => 1024, 'memories.vod.disable' => false, 'memories.vod.vaapi' => true, 'memories.vod.use_transpose' => true, 'updater.release.channel' => 'stable', 'theme' => '', 'loglevel' => 2, 'debug' => false, ); The output of your Apache/nginx/system log in /var/log/____:

cat nextcloud_error.log [Sat Jul 20 00:00:02.162235 2024] [proxy_fcgi:error] [pid 267772:tid 128630459991616] [client 127.0.0.1:52048] AH01071: Got error 'PHP message: PHP Warning: http_response_code(): Cannot set response code - headers already sent (output started at /var/www/nextcloud/apps/richdocumentscode/proxy.php:285) in /var/www/nextcloud/apps/richdocumentscode/proxy.php on line 292'

Output errors in nextcloud.log in /var/www/ or as admin user in top right menu, filtering for errors. Use a pastebin service if necessary.

{"reqId":"22OTaPLUHmCqkxxtLQjr","level":2,"time":"2024-07-20T10:35:11+00:00","remoteAddr":"","user":"--","app":"no app in context","method":"","url":"--","message":"Host localhost was not connected to because it violates local access rules","userAgent":"--","version":"29.0.4.1","data":[]} {"reqId":"2t9EEMUeg3gT7Hqf5Kps","level":2,"time":"2024-07-20T10:36:56+00:00","remoteAddr":"100.69.251.54","user":"jim","app":"suspicious_login","method":"PROPFIND","url":"/remote.php/dav/principals/users/jim/","message":"Could not predict suspiciousness: No models found","userAgent":"macOS/14.5 (23F79) dataaccessd/1.0","version":"29.0.4.1","data":{"app":"suspicious_login"}} {"reqId":"oezME4tJmiDxcU9yfizj","level":2,"time":"2024-07-20T10:36:56+00:00","remoteAddr":"100.69.251.54","user":"jim","app":"suspicious_login","method":"OPTIONS","url":"/remote.php/dav/principals/users/jim/","message":"Could not predict suspiciousness: No models found","userAgent":"macOS/14.5 (23F79) dataaccessd/1.0","version":"29.0.4.1","data":{"app":"suspicious_login"}} {"reqId":"100buz1EqJxrYInHxZDw","level":2,"time":"2024-07-20T10:43:21+00:00","remoteAddr":"100.105.163.64","user":"jim","app":"suspicious_login","method":"OPTIONS","url":"/remote.php/dav/principals/users/jim/","message":"Could not predict suspiciousness: No models found","userAgent":"iOS/17.5.1 (21F90) dataaccessd/1.0","version":"29.0.4.1","data":{"app":"suspicious_login"}} {"reqId":"eMR2JLJP4U2cWE96xIdg","level":2,"time":"2024-07-20T10:43:22+00:00","remoteAddr":"100.105.163.64","user":"jim","app":"suspicious_login","method":"REPORT","url":"/remote.php/dav/addressbooks/users/jim/contacts/","message":"Could not predict suspiciousness: No models found","userAgent":"iOS/17.5.1 (21F90) dataaccessd/1.0","version":"29.0.4.1","data":{"app":"suspicious_login"}} {"reqId":"AV6l0zLVSy6yHgsY1yUs","level":2,"time":"2024-07-20T10:43:22+00:00","remoteAddr":"100.105.163.64","user":"jim","app":"suspicious_login","method":"REPORT","url":"/remote.php/dav/addressbooks/users/jim/z-server-generated--system/","message":"Could not predict suspiciousness: No models found","userAgent":"iOS/17.5.1 (21F90) dataaccessd/1.0","version":"29.0.4.1","data":{"app":"suspicious_login"}} {"reqId":"kBKjbMfLMyoe3U1svqPD","level":2,"time":"2024-07-20T10:43:23+00:00","remoteAddr":"100.105.163.64","user":"jim","app":"suspicious_login","method":"PROPFIND","url":"/remote.php/dav/addressbooks/users/jim/z-app-generated--contactsinteraction--recent/","message":"Could not predict suspiciousness: No models found","userAgent":"iOS/17.5.1 (21F90) dataaccessd/1.0","version":"29.0.4.1","data":{"app":"suspicious_login"}} {"reqId":"jROvGVvJHP6TejSEd4Jp","level":2,"time":"2024-07-20T10:45:25+00:00","remoteAddr":"100.92.218.8","user":"jim","app":"suspicious_login","method":"OPTIONS","url":"/remote.php/dav/principals/users/jim/","message":"Could not predict suspiciousness: No models found","userAgent":"iOS/17.5.1 (21F90) dataaccessd/1.0","version":"29.0.4.1","data":{"app":"suspicious_login"}} {"reqId":"aw2bTx0OlM7dcgpIENRg","level":2,"time":"2024-07-20T10:45:25+00:00","remoteAddr":"100.92.218.8","user":"jim","app":"suspicious_login","method":"REPORT","url":"/remote.php/dav/addressbooks/users/jim/contacts/","message":"Could not predict suspiciousness: No models found","userAgent":"iOS/17.5.1 (21F90) dataaccessd/1.0","version":"29.0.4.1","data":{"app":"suspicious_login"}} {"reqId":"qky5UzHl1Q1RKDS55iiJ","level":2,"time":"2024-07-20T10:45:26+00:00","remoteAddr":"100.92.218.8","user":"jim","app":"suspicious_login","method":"REPORT","url":"/remote.php/dav/addressbooks/users/jim/z-server-generated--system/","message":"Could not predict suspiciousness: No models found","userAgent":"iOS/17.5.1 (21F90) dataaccessd/1.0","version":"29.0.4.1","data":{"app":"suspicious_login"}} {"reqId":"6u0RCnC9eiqbXqCPhP4y","level":2,"time":"2024-07-20T10:45:26+00:00","remoteAddr":"100.92.218.8","user":"jim","app":"suspicious_login","method":"PROPFIND","url":"/remote.php/dav/addressbooks/users/jim/z-app-generated--contactsinteraction--recent/","message":"Could not predict suspiciousness: No models found","userAgent":"iOS/17.5.1 (21F90) dataaccessd/1.0","version":"29.0.4.1","data":{"app":"suspicious_login"}} {"reqId":"HxqCJHonpZGIyMVmUO1q","level":3,"time":"2024-07-20T10:55:02+00:00","remoteAddr":"100.69.251.54","user":"jim","app":"PHP","method":"POST","url":"/apps/notify_push/pre_auth","message":"unlink(/var/www/nextcloud/data/appdata_ocgfs89mpg4c/richdocuments/remoteData/capabilities): No such file or directory at /var/www/nextcloud/lib/private/Files/Storage/Local.php#348","userAgent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/126.0.0.0 Safari/537.36","version":"29.0.4.1","data":{"app":"PHP"}} {"reqId":"YqQRA5IUEa1S11OqZgqB","level":2,"time":"2024-07-20T10:58:53+00:00","remoteAddr":"100.105.163.64","user":"jim","app":"suspicious_login","method":"OPTIONS","url":"/remote.php/dav/principals/users/jim/","message":"Could not predict suspiciousness: No models found","userAgent":"iOS/17.5.1 (21F90) dataaccessd/1.0","version":"29.0.4.1","data":{"app":"suspicious_login"}} {"reqId":"HJ0H6BbgRGoApQ2pweh8","level":2,"time":"2024-07-20T10:58:54+00:00","remoteAddr":"100.105.163.64","user":"jim","app":"suspicious_login","method":"REPORT","url":"/remote.php/dav/addressbooks/users/jim/contacts/","message":"Could not predict suspiciousness: No models found","userAgent":"iOS/17.5.1 (21F90) dataaccessd/1.0","version":"29.0.4.1","data":{"app":"suspicious_login"}} {"reqId":"ahXynKLRl905Si7ZQWAy","level":2,"time":"2024-07-20T10:58:54+00:00","remoteAddr":"100.105.163.64","user":"jim","app":"suspicious_login","method":"REPORT","url":"/remote.php/dav/addressbooks/users/jim/z-server-generated--system/","message":"Could not predict suspiciousness: No models found","userAgent":"iOS/17.5.1 (21F90) dataaccessd/1.0","version":"29.0.4.1","data":{"app":"suspicious_login"}} {"reqId":"7lYlTwRemHLHX2iDeUTr","level":2,"time":"2024-07-20T10:58:55+00:00","remoteAddr":"100.105.163.64","user":"jim","app":"suspicious_login","method":"PROPFIND","url":"/remote.php/dav/addressbooks/users/jim/z-app-generated--contactsinteraction--recent/","message":"Could not predict suspiciousness: No models found","userAgent":"iOS/17.5.1 (21F90) dataaccessd/1.0","version":"29.0.4.1","data":{"app":"suspicious_login"}} {"reqId":"M4kbLSeSgnmZFc6gzMl2","level":4,"time":"2024-07-20T11:00:04+00:00","remoteAddr":"100.69.251.54","user":"jim","app":"no app in context","method":"GET","url":"/apps/serverinfo/update","message":"Could not boot richdocuments: /appdata_ocgfs89mpg4c/richdocuments/remoteData/discovery","userAgent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/126.0.0.0 Safari/537.36","version":"29.0.4.1","exception":{"Exception":"OCP\Files\NotFoundException","Message":"/appdata_ocgfs89mpg4c/richdocuments/remoteData/discovery","Code":0,"Trace":[{"file":"/var/www/nextcloud/lib/private/Files/Node/Folder.php","line":135,"function":"get","class":"OC\Files\Node\Root","type":"->"},{"file":"/var/www/nextcloud/lib/private/Files/SimpleFS/SimpleFolder.php","line":75,"function":"get","class":"OC\Files\Node\Folder","type":"->"},{"file":"/var/www/nextcloud/apps/richdocuments/lib/Service/CachedRequestService.php","line":89,"function":"getFile","class":"OC\Files\SimpleFS\SimpleFolder","type":"->"},{"file":"/var/www/nextcloud/apps/richdocuments/lib/AppInfo/Application.php","line":206,"function":"resetCache","class":"OCA\Richdocuments\Service\CachedRequestService","type":"->"},{"file":"/var/www/nextcloud/apps/richdocuments/lib/AppInfo/Application.php","line":165,"function":"checkAndEnableCODEServer","class":"OCA\Richdocuments\AppInfo\Application","type":"->"},{"file":"/var/www/nextcloud/lib/private/AppFramework/Bootstrap/Coordinator.php","line":200,"function":"boot","class":"OCA\Richdocuments\AppInfo\Application","type":"->"},{"file":"/var/www/nextcloud/lib/private/App/AppManager.php","line":437,"function":"bootApp","class":"OC\AppFramework\Bootstrap\Coordinator","type":"->"},{"file":"/var/www/nextcloud/lib/private/App/AppManager.php","line":216,"function":"loadApp","class":"OC\App\AppManager","type":"->"},{"file":"/var/www/nextcloud/lib/private/legacy/OC_App.php","line":128,"function":"loadApps","class":"OC\App\AppManager","type":"->"},{"file":"/var/www/nextcloud/lib/base.php","line":1030,"function":"loadApps","class":"OC_App","type":"::"},{"file":"/var/www/nextcloud/index.php","line":49,"function":"handleRequest","class":"OC","type":"::"}],"File":"/var/www/nextcloud/lib/private/Files/Node/Root.php","Line":212,"message":"Could not boot richdocuments: /appdata_ocgfs89mpg4c/richdocuments/remoteData/discovery","exception":{},"CustomMessage":"Could not boot richdocuments: /appdata_ocgfs89mpg4c/richdocuments/remoteData/discovery"}} {"reqId":"4cEX5VTdyCBNkwhHv3DD","level":2,"time":"2024-07-20T11:00:31+00:00","remoteAddr":"100.100.234.145","user":"jim","app":"suspicious_login","method":"OPTIONS","url":"/remote.php/dav/principals/users/jim/","message":"Could not predict suspiciousness: No models found","userAgent":"macOS/14.5 (23F79) AddressBookCore/2571.3","version":"29.0.4.1","data":{"app":"suspicious_login"}}

juliushaertl commented 3 weeks ago

The trace seems to come from the built-in CODE server autoconfiguration which I could imagine causing some concurrency issues then on 29. With 30 this should no longer be a problem as per https://github.com/nextcloud/richdocuments/pull/3762 but haven't looked into in depth on how this could happen and be prevented on 29 yet.

scubamuc commented 3 weeks ago

@juliushaertl

The trace seems to come from the built-in CODE server autoconfiguration which I could imagine causing some concurrency issues

thanks for the heads up... looking forward to 30 and will keep an eye on this when testing the snap.

had to revise my original comment since the logs began getting errors again... the issue has no effect on functionality though. if you need that bash-script again, don't hesitate to request... 🥽👌