[Bug]: A lot of log messages "Access to this resource has been denied because it is in view-only mode."

alx-tuilmenau commented 1 year ago

⚠️ This issue respects the following points: ⚠️

[X] This is a bug, not a question or a configuration/webserver/proxy issue.
[X] This issue is not already reported on Github (I've searched it).
[X] Nextcloud Server is up to date. See Maintenance and Release Schedule for supported versions.
[X] Nextcloud Server is running on 64bit capable CPU, PHP and OS.
[X] I agree to follow Nextcloud's Code of Conduct.

Bug description

There are a lot of messages "Access to this resource has been denied because it is in view-only mode." in the log. The error message itself is correct, but it is logged on every Client sync, which creates a lot of messages. It should not logged on every file access.

Steps to reproduce

User A uses the desktop Client to sync all files
User B shares a folder (with files in it) with user A, and disabled the "download" permission on this share
The client of User A can't download the file and triggers the log message on every file with every sync

Expected behavior

The error is returned to the client, but not logged every time.

Installation method

Community Manual installation with Archive

Operating system

Debian/Ubuntu

PHP engine version

PHP 8.0

Web server

Apache (supported)

Database engine version

MariaDB

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

Updated from a minor version (ex. 22.2.3 to 22.2.4)

Are you using the Nextcloud Server Encryption module?

None

What user-backends are you using?

[X] Default user-backend (database)
[X] LDAP/ Active Directory
[ ] SSO - SAML
[ ] Other

Configuration report

{
    "system": {
        "instanceid": "***REMOVED SENSITIVE VALUE***",
        "passwordsalt": "***REMOVED SENSITIVE VALUE***",
        "secret": "***REMOVED SENSITIVE VALUE***",
        "trusted_domains": [
            "***REMOVED SENSITIVE VALUE***",
            "***REMOVED SENSITIVE VALUE***"
        ],
        "datadirectory": "***REMOVED SENSITIVE VALUE***",
        "dbtype": "mysql",
        "version": "24.0.7.1",
        "dbname": "***REMOVED SENSITIVE VALUE***",
        "dbhost": "***REMOVED SENSITIVE VALUE***",
        "dbport": "",
        "dbtableprefix": "oc_",
        "mysql.utf8mb4": true,
        "dbuser": "***REMOVED SENSITIVE VALUE***",
        "dbpassword": "***REMOVED SENSITIVE VALUE***",
        "dbdriveroptions": {
            "1002": "SET wait_timeout = 28800"
        },
        "installed": true,
        "default_language": "de",
        "updatechecker": true,
        "has_internet_connection": true,
        "memcached_servers": [
            [
                "localhost",
                11211
            ]
        ],
        "appstoreenabled": true,
        "ldapIgnoreNamingRules": false,
        "ldapProviderFactory": "\\OCA\\User_LDAP\\LDAPProviderFactory",
        "loglevel": 2,
        "trusted_proxies": "***REMOVED SENSITIVE VALUE***",
        "forwarded_for_headers": [
            "HTTP_X_FORWARDED_FOR"
        ],
        "overwritehost": "***REMOVED SENSITIVE VALUE***",
        "overwriteprotocol": "https",
        "overwrite.cli.url": "***REMOVED SENSITIVE VALUE***",
        "mail_from_address": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpmode": "smtp",
        "mail_domain": "***REMOVED SENSITIVE VALUE***",
        "skeletondirectory": "\/data\/nextcloud_skel",
        "theme": "***REMOVED SENSITIVE VALUE***",
        "activity_expire_days": 14,
        "integrity.check.disabled": true,
        "memcache.local": "\\OC\\Memcache\\APCu",
        "memcache.distributed": "\\OC\\Memcache\\Redis",
        "memcache.locking": "\\OC\\Memcache\\Redis",
        "redis": {
            "host": "***REMOVED SENSITIVE VALUE***",
            "port": 6379,
            "password": "***REMOVED SENSITIVE VALUE***"
        },
        "knowledgebaseenabled": false,
        "defaultapp": "apporder",
        "sharing.minSearchStringLength": 4,
        "sharing.maxAutocompleteResults": 5,
        "maintenance": false,
        "debug": false,
        "htaccess.RewriteBase": "\/",
        "proxy": "***REMOVED SENSITIVE VALUE***",
        "mail_smtphost": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpport": "25",
        "updater.release.channel": "stable",
        "lookup_server": "",
        "app_install_overwrite": [
            "files_upload_mtime",
            "quotaadmin",
            "drop_account",
            "gpxedit",
            "twofactor_u2f"
        ],
        "preview_max_x": 400,
        "preview_max_y": 400,
        "preview_max_scale_factor": 1.5,
        "tempdirectory": "\/data\/tmp\/nextcloud",
        "localstorage.allowsymlinks": true,
        "hashingMemoryCost": 8,
        "default_phone_region": "de",
        "upgrade.disable-web": true,
        "preview_max_filesize_image": 10,
        "enabledPreviewProviders": [
            "OC\\Preview\\PNG",
            "OC\\Preview\\JPEG",
            "OC\\Preview\\GIF",
            "OC\\Preview\\BMP",
            "OC\\Preview\\XBitmap",
            "OC\\Preview\\MP3",
            "OC\\Preview\\TXT",
            "OC\\Preview\\MarkDown",
            "OC\\Preview\\PDF",
            "OC\\Preview\\Postscript",
            "OC\\Preview\\SVG"
        ],
        "profile.enabled": false
    }
}

List of activated Apps

Enabled:
  - accessibility: 1.10.0
  - activity: 2.16.0
  - announcementcenter: 6.3.1
  - apporder: 0.15.0
  - bruteforcesettings: 2.4.0
  - calendar: 3.5.2
  - circles: 24.0.1
  - cloud_federation_api: 1.7.0
  - comments: 1.14.0
  - contacts: 4.2.2
  - contactsinteraction: 1.5.0
  - dav: 1.22.0
  - deck: 1.7.3
  - drawio: 1.0.5
  - drop_account: 2.1.0
  - federatedfilesharing: 1.14.0
  - federation: 1.14.0
  - files: 1.19.0
  - files_antivirus: 4.0.1
  - files_downloadactivity: 1.15.0
  - files_mindmap: 0.0.27
  - files_pdfviewer: 2.5.0
  - files_retention: 1.13.2
  - files_rightclick: 1.3.0
  - files_sharing: 1.16.2
  - files_trashbin: 1.14.0
  - files_versions: 1.17.0
  - files_videoplayer: 1.13.0
  - forms: 2.5.1
  - gpxedit: 0.0.14
  - guests: 2.3.0
  - impersonate: 1.11.0
  - logreader: 2.9.0
  - lookup_server_connector: 1.12.0
  - metadata: 0.17.0
  - notes: 4.5.1
  - notifications: 2.12.1
  - oauth2: 1.12.0
  - photos: 1.6.0
  - polls: 3.8.3
  - provisioning_api: 1.14.0
  - quota_warning: 1.15.0
  - quotaadmin: 0.0.3
  - recommendations: 1.3.0
  - richdocuments: 6.3.1
  - serverinfo: 1.14.0
  - settings: 1.6.0
  - spreed: 14.0.7
  - systemtags: 1.14.0
  - tasks: 0.14.5
  - text: 3.5.1
  - twofactor_backupcodes: 1.13.0
  - twofactor_totp: 6.4.1
  - twofactor_u2f: 6.3.1
  - twofactor_webauthn: 0.3.3
  - updatenotification: 1.14.0
  - user_ldap: 1.14.1
  - viewer: 1.8.0
  - weather_status: 1.4.0
  - workflowengine: 2.6.0

Nextcloud Signing status

Integrity checker has been disabled. Integrity cannot be verified.

Nextcloud Logs

I got hundreds of lines like this, but I don't want anonymize and post all, they differ only in the file path.

{"reqId":"gE06YAYd1et6r4naoBln","level":4,"time":"2022-12-08T09:38:31+00:00","remoteAddr":"*** REMOVED ***","user":"*** REMOVED ***","app":"webdav","method":"GET","url":"/remote.php/dav/files/*** REMOVED ***/Readme.md","message":"Access to this resource has been denied because it is in view-only mode.","userAgent":"Mozilla/5.0 (Windows) mirall/3.6.0stable-Win64 (build 20220906) (Nextcloud, windows-10.0.19045 ClientArchitecture: x86_64 OsArchitecture: x86_64)","version":"24.0.7.1","exception":{"Exception":"OCA\\DAV\\Connector\\Sabre\\Exception\\Forbidden","Message":"Access to this resource has been denied because it is in view-only mode.","Code":0,"Trace":[{"file":"/data/nextcloud_a1/3rdparty/sabre/event/lib/WildcardEmitterTrait.php","line":89,"function":"checkViewOnly","class":"OCA\\DAV\\DAV\\ViewOnlyPlugin","type":"->"},{"file":"/data/nextcloud_a1/3rdparty/sabre/dav/lib/DAV/Server.php","line":472,"function":"emit","class":"Sabre\\DAV\\Server","type":"->"},{"file":"/data/nextcloud_a1/3rdparty/sabre/dav/lib/DAV/Server.php","line":253,"function":"invokeMethod","class":"Sabre\\DAV\\Server","type":"->"},{"file":"/data/nextcloud_a1/3rdparty/sabre/dav/lib/DAV/Server.php","line":321,"function":"start","class":"Sabre\\DAV\\Server","type":"->"},{"file":"/data/nextcloud_a1/apps/dav/lib/Server.php","line":358,"function":"exec","class":"Sabre\\DAV\\Server","type":"->"},{"file":"/data/nextcloud_a1/apps/dav/appinfo/v2/remote.php","line":35,"function":"exec","class":"OCA\\DAV\\Server","type":"->"},{"file":"/data/nextcloud_a1/remote.php","line":170,"args":["/data/nextcloud_a1/apps/dav/appinfo/v2/remote.php"],"function":"require_once"}],"File":"/data/nextcloud_a1/apps/dav/lib/DAV/ViewOnlyPlugin.php","Line":96,"CustomMessage":"--"},"id":"6391b3c440366"}

Additional info

No response

EricThi commented 1 year ago

Same case after migrate to last V24 to V25.0.2 Kernel: 5.17.9-arch1-1 mariadb Ver 15.1 Distrib 10.7.3-MariaDB, for Linux (x86_64) using readline 5.1 nginx/1.20.2 PHP 8.1.6 (cli) (built: May 15 2022 06:10:08) (NTS) Copyright (c) The PHP Group Zend Engine v4.1.6, Copyright (c) Zend Technologies with Zend OPcache v8.1.6, Copyright (c), by Zend Technologies

build manually never see this error on log before upgrade V24.0.5 to V25

EricThi commented 1 year ago

Patch are linked for this case no ? https://github.com/nextcloud/server/pull/35213

If found time, i will test on my preprod for this case

solracsf commented 1 year ago

@EricThi any feedback?

nextcloud-command commented 1 year ago

This issue has been automatically marked as stale because it has not had recent activity and seems to be missing some essential information. It will be closed if no further activity occurs. Thank you for your contributions.

quentinDupont commented 11 months ago

I have this issue with Nextcloud 26. Do you suceed to solve it ? @alx-tuilmenau @EricThi @solracsf

alx-tuilmenau commented 11 months ago

I have to edit this message: I got these message again. For a long time, there were no messages, but maybe there was simply no folder without "download" permission. There are 2 different cases:

"Download" is deactivated for a shared folder and the listing of image files in the files app is causing the message. Preview returns 403, the JS tries to get the image instead, getting also 403 but also producing the log message.
"Download" is deactivated for a shared folder and a client tries to sync the folder, tries to download every file, with a message for every file in the log (this is the case is the original one)

NC 26.0.5

Does it make sense to show the filenames of files that cannot be downloaded ? For the web files app maybe it's necessary for the secure viewer, but is there any need to show the filenames to a normal client (or show filenames where no secure viewer is available) ?

joshtrichards commented 7 months ago

This seems to be three different issues:

The original matter, for the most part, I think this is largely a client matter. If a client sees that the download permission isn't permitted for a file it should not attempt to download it. It appears the desktop client is the one in use here, so I suggest filing an enhancement request in the https://github.com/nextcloud/desktop repository to have that client's sync engine check for download permissions before, well, downloading. I have no idea how those files should get presented in the GUI or VFS, but that's an implementation discussion for the Issue in that repository. :-)
The log level in server for the Forbidden exception is overly high IMO for this particular scenario (INFO level 1 seems more appropriate to me or even DEBUG level 0 + admit_audit logging), but since the Forbidden exception is used generically for other situations it's a bit more of a complicated change than just changing the embedded log level. It's also less of an issue if clients stop doing GETs on files they can't download. :-)
Previews: Seems plausible, but didn't look into it.

kernstock commented 5 months ago

The log level in server for the Forbidden exception is overly high IMO for this particular scenario

This. Even more, I think a resilient server should expect whatever client comes around and requests access to resources it has no permission for. This is not an error and should not be logged as one. This is what try/catch mechanisms are perfectly suited for (though I can't tell for php).

It's also less of an issue if clients stop doing GETs on files they can't download. :-)

Delegating responsibility for internal misconceptions to clients that is.

kernstock commented 5 months ago

I think the above does also apply to this error message:

OCA\DAV\Connector\Sabre\Exception\Forbidden: No read permissions. This might be caused by files_accesscontrol, check your configured rules

nextcloud / server