nextcloud / server

☁️ Nextcloud server, a safe home for all your data
https://nextcloud.com
GNU Affero General Public License v3.0
27.56k stars 4.08k forks source link

[Bug]: OCP\Files\NotFoundException: /MyMusicLibrary #36019

Open xinstein opened 1 year ago

xinstein commented 1 year ago

⚠️ This issue respects the following points: ⚠️

Bug description

OCP\Files\NotFoundException: /{username}/files/MyMusicLibrary
at lib/private/Files/Node/Root.php line 209

                               0. .../LazyUserFolder.php line 59
                                  OC\Files\Node\Root->get("\/{username}\/files\/MyMusicLibrary... y")
                               1. .../Util.php line 281
                                  OC\Files\Node\LazyUserFolder->get("\/MyMusic ... /")
                               2. .../LibrarySettings.php line 107
                                  OCA\Music\Utility\Util::getFolderFromRelativePath(
                                    OC\Files\Node\LazyUserFolder  ... {},
                                    "\/MyMusicLibrary\ ... /"
                                  )
                               3. .../SubsonicController.php line 1104
                                  OCA\Music\Utility\LibrarySettings->getFolder("{username}")
                               4. .../SubsonicController.php line 225
                                  OCA\Music\Controller\SubsonicController->getIndexesForFolders(

                                  )
                               5. .../SubsonicController.php line 177
                                  OCA\Music\Controller\SubsonicController->getIndexes(
                                    "fold ... s"
                                  )
                               6. .../Dispatcher.php line 225
                                  OCA\Music\Controller\SubsonicController->handleRequest(
                                    "getI ... s"
                                  )
                               7. .../Dispatcher.php line 133
                                  OC\AppFramework\Http\Dispatcher->executeController(
                                    OCA\Music\Controller\SubsonicController ... {},
                                    "handleReque ... t"
                                  )
                               8. .../App.php line 172
                                  OC\AppFramework\Http\Dispatcher->dispatch(
                                    OCA\Mu ... {},
                                    "handl ... t"
                                  )
                               9. .../Route/Router.php line 298
                                  OC\AppFramework\App::main(
                                    "SubsonicController",
                                    "handleRequest",
                                    OC\AppFramework\Depend ... {},
                                    ["getIndexes.view","mu ... "]
                                  )
                              10. lib/base.php line 1030
                                  OC\Route\Router->match("\/apps\/music\/subsonic\ ... w")
                              11. index.php line 36
                                  OC::handleRequest(

/MyMusicLibrary is an external storage (files_external) of local directory

This happens most of the time, except when the directory /MyMusicLibrary has just been accessed in the Files app.

This problem is not present in 24.0.5.1, I recently upgraded to 24.0.8.2 and this is when the problem starts to happen. I now upgraded to 25.0.2.3 and the problem still persists.

Steps to reproduce

  1. Let the server be idle for a while
  2. Use any subsonic client to access my Nextcloud Music Library as I usually do.
  3. The FileNotFound exception happens.
  4. Open the music library folder (which is an external storage) in Files app in the web browser
  5. redo step 2
  6. The FileNotFound exception does not happen, and I can use my music library normally.
  7. Enjoy music for a while.
  8. The FileNotFound exception recurs.

This problem specifically affects ONLY subsonic clients, the music webapp works seamlessly as usual.

Expected behavior

It should work as in previous versions.

Installation method

Community Docker image

Operating system

Debian/Ubuntu

PHP engine version

None

Web server

Nginx

Database engine version

MySQL

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?

Encryption is Disabled

What user-backends are you using?

Configuration report

{
    "system": {
        "allow_local_remote_servers": true,
        "memcache.local": "\\OC\\Memcache\\APCu",
        "apps_paths": [
            {
                "path": "\/var\/www\/html\/apps",
                "url": "\/apps",
                "writable": false
            },
            {
                "path": "\/var\/www\/html\/custom_apps",
                "url": "\/custom_apps",
                "writable": true
            }
        ],
        "memcache.distributed": "\\OC\\Memcache\\Redis",
        "memcache.locking": "\\OC\\Memcache\\Redis",
        "overwriteprotocol": "https",
        "trashbin_retention_obligation": 30,
        "overwritehost": "***REMOVED SENSITIVE VALUE***",
        "overwrite.cli.url": "https:\/\/***REMOVED SENSITIVE VALUE***",
        "mail_smtpmode": "smtp",
        "mail_smtpsecure": "ssl",
        "mail_smtpstreamoptions": {
            "ssl": {
                "allow_self_signed": true,
                "verify_peer": false,
                "verify_peer_name": false
            }
        },
        "mail_sendmailmode": "smtp",
        "mail_from_address": "***REMOVED SENSITIVE VALUE***",
        "mail_domain": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpauth": 1,
        "mail_smtphost": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpport": "465",
        "mail_smtpname": "***REMOVED SENSITIVE VALUE***",
        "mail_smtppassword": "***REMOVED SENSITIVE VALUE***",
        "enable_previews": true,
        "enabledPreviewProviders": {
            "0": "OC\\Preview\\TXT",
            "1": "OC\\Preview\\MarkDown",
            "2": "OC\\Preview\\OpenDocument",
            "3": "OC\\Preview\\PDF",
            "4": "OC\\Preview\\MSOffice2003",
            "5": "OC\\Preview\\MSOfficeDoc",
            "7": "OC\\Preview\\Image",
            "8": "OC\\Preview\\Photoshop",
            "9": "OC\\Preview\\TIFF",
            "10": "OC\\Preview\\SVG",
            "11": "OC\\Preview\\Font",
            "12": "OC\\Preview\\MP3",
            "13": "OC\\Preview\\Movie",
            "14": "OC\\Preview\\MKV",
            "15": "OC\\Preview\\MP4",
            "16": "OC\\Preview\\AVI",
            "17": "OC\\Preview\\HEIC",
            "18": "OC\\Preview\\BMP"
        },
        "redis": {
            "host": "***REMOVED SENSITIVE VALUE***",
            "password": "***REMOVED SENSITIVE VALUE***",
            "port": 6379
        },
        "instanceid": "***REMOVED SENSITIVE VALUE***",
        "passwordsalt": "***REMOVED SENSITIVE VALUE***",
        "secret": "***REMOVED SENSITIVE VALUE***",
        "trusted_domains": [
            "***REMOVED SENSITIVE VALUE***"
        ],
        "trusted_proxies": "***REMOVED SENSITIVE VALUE***",
        "datadirectory": "***REMOVED SENSITIVE VALUE***",
        "dbtype": "mysql",
        "version": "24.0.8.2",
        "dbname": "***REMOVED SENSITIVE VALUE***",
        "dbhost": "***REMOVED SENSITIVE VALUE***",
        "dbport": "",
        "dbtableprefix": "oc_",
        "mysql.utf8mb4": true,
        "dbuser": "***REMOVED SENSITIVE VALUE***",
        "dbpassword": "***REMOVED SENSITIVE VALUE***",
        "installed": true,
        "loglevel": 1,
        "ncd_disable_bt": "1",
        "ncd_yt_binary": "\/usr\/bin\/youtube-dl",
        "ncd_rpctoken": "",
        "maintenance": false,
        "app_install_overwrite": [
            "ssepush",
            "epubreader"
        ],
        "theme": "",
        "ncd_admin_settings": {
            "disallow_aria2_settings": "1"
        },
        "app.mail.verify-tls-peer": false,
        "logtimezone": "Asia\/Shanghai",
        "logfile": "\/var\/www\/html\/data\/nextcloud_logs\/nextcloud.log",
        "log_rotate_size": 104857600,
        "data-fingerprint": "6091e96366b06350ba0ec477ec934e2e"
    }
}

List of activated Apps

Enabled:
  - accessibility: 1.10.0
  - activity: 2.16.0
  - apporder: 0.15.0
  - bookmarks: 11.0.4
  - bruteforcesettings: 2.4.0
  - calendar: 3.5.4
  - cloud_federation_api: 1.7.0
  - comments: 1.14.0
  - contacts: 4.2.3
  - contactsinteraction: 1.5.0
  - cospend: 1.4.10
  - dashboard: 7.4.0
  - dav: 1.22.0
  - event_update_notification: 2.0.0
  - federatedfilesharing: 1.14.0
  - files: 1.19.0
  - files_external: 1.16.1
  - files_markdown: 2.3.6
  - 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
  - firstrunwizard: 2.13.0
  - gpoddersync: 3.7.1
  - logreader: 2.9.0
  - lookup_server_connector: 1.12.0
  - music: 1.8.0
  - ncdownloader: 1.0.2
  - news: 20.0.0
  - notifications: 2.12.1
  - notify_push: 0.5.0
  - oauth2: 1.12.0
  - password_policy: 1.14.0
  - passwords: 2022.12.21
  - photos: 1.6.0
  - privacy: 1.8.0
  - provisioning_api: 1.14.0
  - recommendations: 1.3.0
  - richdocuments: 6.3.2
  - serverinfo: 1.14.0
  - settings: 1.6.0
  - sharebymail: 1.14.0
  - spreed: 14.0.7
  - ssepush: 0.0.6
  - systemtags: 1.14.0
  - tasks: 0.14.5
  - text: 3.5.1
  - theming: 1.15.0
  - twofactor_backupcodes: 1.13.0
  - twofactor_totp: 6.4.1
  - user_status: 1.4.0
  - viewer: 1.8.0
  - weather_status: 1.4.0
  - workflowengine: 2.6.0
Disabled:
  - admin_audit
  - circles: 22.3.0
  - encryption: 2.10.0
  - federation: 1.12.0
  - groupfolders: 12.0.2
  - imageconverter: 1.3.4
  - mail: 1.15.1
  - nextcloud_announcements: 1.11.0
  - support: 1.5.0
  - survey_client: 1.10.0
  - updatenotification: 1.12.0
  - user_ldap: 1.12.2

Nextcloud Signing status

Technical information
=====================
The following list covers which files have failed the integrity check. Please read
the previous linked documentation to learn more about the errors and how to fix
them.

Results
=======
- core
    - INVALID_HASH
        - core/js/mimetypelist.js

Raw output
==========
Array
(
    [core] => Array
        (
            [INVALID_HASH] => Array
                (
                    [core/js/mimetypelist.js] => Array
                        (
                            [expected] => 94195a260a005dac543c3f6aa504f1b28e0078297fe94a4f52f012c16c109f0323eecc9f767d6949f860dfe454625fcaf1dc56f87bb8350975d8f006bbbdf14a
                            [current] => 1b07fb272efa65a10011ed52a6e51260343c5de2a256e1ae49f180173e2b6684ccf90d1af3c19fa97c31d42914866db46e3216883ec0d6a82cec0ad5529e78b1
                        )

                )

        )

)

What's this? I've never noticed this problem.

I've done an ./occ maintenance:mimetype:update-js, Has this anything to do with this integrity failure?

Nextcloud Logs

No response

Additional info

No response

szaimen commented 1 year ago

Hi, this is possibly a bug of the music app. Please also report it here: https://github.com/owncloud/music/issues

paulijar commented 1 year ago

The Music app doesn't do anything too exotic in this case. In essence, it calls IRootFolder::getUserFolder($userId) to get the home folder of the targeted user and then calls Folder::get($path) on that home folder object to get the folder which has been configured as the music library root for that user. This happens in a context where there is no logged-in user.

kesselb commented 1 year ago

Open the music library folder (which is an external storage) in Files app in the web browser

Hi, are you using the session credentials to authenticate the external storage?

xinstein commented 1 year ago

It's a local mount

Open the music library folder (which is an external storage) in Files app in the web browser

Hi, are you using the session credentials to authenticate the external storage?

It's a local mount, I don't think it needs a credential.

The mount is a vhgfs from a windows directory.

Heres my full setup:

Windows 10 host, ubuntu 20.04 guest in virtualbox, nextcloud is installed via docker-compose in ubuntu. The music folder is a windows directory of an ntfs drive, mounted in ubuntu using virtualbox's vhgfs, bind-mounted in nextcloud's docker-compose configuration.

I've been using this setup since more than two years ago, and music app is among my most intensely used apps.

xinstein commented 1 year ago

Forgot to mention that the Music web app works without any problem.

xinstein commented 1 year ago

I just confirmed that this problem still persists in nxtcloud 25.0.2.3

xinstein commented 1 year ago

This problem might not be specific to the music app.

I get 'file not found' notices from time to time when using the files app, but this is much harder to reproduce. Currently all observed occurrences are in folders of external storage, but that's not a sure thing.

I feel it necessary to also report this bug to files_external app

xinstein commented 1 year ago

What's the status of this issue ? What more info should I provide ?

wwklnd commented 1 year ago

I do not have the music app installed, and after upgrading to Nextcloud 26.0 I get this warning: image

Clicking the "List of invalid files..." link gives me this:

Technical information
=====================
The following list covers which files have failed the integrity check. Please read
the previous linked documentation to learn more about the errors and how to fix
them.

Results
=======
- core
    - INVALID_HASH
        - core/js/mimetypelist.js

Raw output
==========
Array
(
    [core] => Array
        (
            [INVALID_HASH] => Array
                (
                    [core/js/mimetypelist.js] => Array
                        (
                            [expected] => 4b0a99fbab7bc4824176101150bd0ab2b553e128a390e0f872580db4541462b31aad13099fd41533b6695d1b185dabca26a45e9a78227cfb9479eafa439c7bff
                            [current] => a8e818876a7eff2a2137601eafc6c7d96b99cbf27d94ff9bb59eb237bdab92076ecc2828242bb37551c9c8b6772c0718887bd49cee5b49b3be48d3b9ecaa558f
                        )

                )

        )

)

Possibly related?

paulijar commented 1 year ago

@wwklnd Even though you have the same integrity check failure as the OP, I don't believe that this has anything to do with the actual problem reported here, neither in your nor in the OP's case. It just means that for both of you, this one file core/js/mimetypelist.js has been modified by someone after the Nextcloud installation.

wwklnd commented 1 year ago

@paulijar Gotcha!

h4n23s commented 1 year ago

I managed to narrow this issue down to a couple of methods.

To begin with, here's a simplified call stack for the music app when a music stream is requested via a client:

1. OCA\Music\Controller\SubsonicController->stream("track-5815")
2. OCA\Music\Controller\SubsonicController->download("track-5815")
3. OCA\Music\Controller\SubsonicController->getFilesystemNode(50253)
4. OCA\Music\Utility\LibrarySettings->getFolder("<username>")
5. OCA\Music\Utility\Util::getFolderFromRelativePath(["OC\\Files\\Node\\LazyUserFolder"], "/My Music/")
6. OC\Files\Node\LazyUserFolder->get("/My Music/")
7. OC\Files\Node\Root->get("/<username>/files/My Music")

The last method (Root::get() : Node) makes a call to View::getFileInfo() : FileInfo which itself queries Filesystem::getMountManager()->find() : Mount to retrieve the matching Mount and Storage objects for a given path.

View::getFileInfo() : FileInfo then calls the View::getCacheEntry() : ICacheEntry method (passing the Storage object and file path as parameters) which tries to retrieve data (file metadata?) from a cache or tries to load it directly from storage if there is a cache miss.

Now, here's the interesting part: In case of a cache miss, the Storage object is used to check if the file even still exists (using Storage::file_exists() : boolean). This should return true assuming that Filesystem::getMountManager()->find() : Mount returns the correct Mount and Storage objects.

I've observed that for the root path of local external storages (in my case "/My Music"), the home::<username> Storage object is returned (the home storage for a particular user is located at /var/www/html/data/<username>/files).

This is causing the file_exists() check to fail because there is no such folder in my home storage - it's the name of my share.

h4n23s commented 1 year ago

Here's my current workaround (which will only work if your "Music" folder is a child of the root user folder): I've added a call to Folder::getDirectoryListing() in the LibrarySettings::getFolder() method.

public function getFolder(string $userId) : Folder {
    $userHome = $this->rootFolder->getUserFolder($userId);
    $path = $this->getPath($userId);

    $userHome->getDirectoryListing();
    return Util::getFolderFromRelativePath($userHome, $path);
}
szaimen commented 1 year ago

Hi, please update to 25.0.7 or better 26.0.2 and report back if it fixes the issue. Thank you!

My goal is to add a label like e.g. 26-feedback to this ticket of an up-to-date major Nextcloud version where the bug could be reproduced. However this is not going to work without your help. So thanks for all your effort!

If you don't manage to reproduce the issue in time and the issue gets closed but you can reproduce the issue afterwards, feel free to create a new bug report with up-to-date information by following this link: https://github.com/nextcloud/server/issues/new?assignees=&labels=bug%2C0.+Needs+triage&template=BUG_REPORT.yml&title=%5BBug%5D%3A+

h4n23s commented 1 year ago

Just performed an upgrade to NC 26.0.2. Unfortunately the issue was not fixed and the proposed workaround is still valid.

szaimen commented 1 year ago

Here's my current workaround (which will only work if your "Music" folder is a child of the root user folder): I've added a call to Folder::getDirectoryListing() in the LibrarySettings::getFolder() method.

public function getFolder(string $userId) : Folder {
    $userHome = $this->rootFolder->getUserFolder($userId);
    $path = $this->getPath($userId);

    $userHome->getDirectoryListing();
    return Util::getFolderFromRelativePath($userHome, $path);
}

This sounds like a fix in the music app then. Cc @paulijar

h4n23s commented 1 year ago

Oh, I don't think that's a good idea. This issue affects other apps (e.g. files, notes) as well, but it may not be as noticeable. Please see my previous comment on this thread:

In case of a cache miss, the Storage object is used to check if the file even still exists (using Storage::file_exists() : boolean). This should return true assuming that Filesystem::getMountManager()->find() : Mount returns the correct Mount and Storage objects.

I've observed that for the root path of local external storages (in my case "/My Music"), the home::<username> Storage object is returned (the home storage for a particular user is located at /var/www/html/data/<username>/files).

This is causing the file_exists() check to fail because there is no such folder in my home storage - it's the name of my share.

szaimen commented 1 year ago

Cc @icewind then 🤷‍♂️

h4n23s commented 1 year ago

Maybe I'm missing something here, but I think you were trying to mention @icewind1991? :sweat_smile:

h4n23s commented 1 year ago

This may not be a caching issue.

I've observed that after some time (30 seconds to a few minutes) almost every external mount point is removed from the oc_mounts table. It appears that when the getDirectoryListing() method is invoked on the user's root folder, all external mount points are subsequently reinserted into the table.

I've also noticed that one mount point entry (see screenshots) is duplicated several times for the same user but with different root_ids.

Before reloading the root directory After reloading the root directory
image image
h4n23s commented 1 year ago

Possibly related to #40353.

h4n23s commented 11 months ago

This issue is still present on Nextcloud server v28.0.0

xinstein commented 8 months ago

This issue is not present on 24.0.5.1, and present on 24.0.8.2. Is that not specific enough to find a cause?

xinstein commented 7 months ago

The issue seems to be gone, I recently updated from

  'version' => '27.1.5.1',

to

  'version' => '27.1.7.2',

Thought I should report here.

So what's the status of this issue on 28.x.x