[Bug]: Race condition and misleading exception on concurrent preview generation requests for the same file

[jszeibert]

⚠️ This issue respects the following points: ⚠️

• This is a bug, not a question or a configuration/webserver/proxy issue.
• This issue is not already reported on Github OR Nextcloud Community Forum (I've searched it).
• Nextcloud Server is up to date. See Maintenance and Release Schedule for supported versions.
• I agree to follow Nextcloud's Code of Conduct.

Bug description

For context:

This issue was discoverd with nextcloud/deck#5035 which introduced a new feature that shows attachments of a card not only in the attachment list in the sidebar, but also as cover image to a card.
Uploading an image therefore triggers two concurrent preview generation request with different sizes, leading to a race condition in the Preview Generator.
The effect is that only one of the requests returns the preview image the other throws the missleading Exception:

...
   "exception":{
      "Exception":"OCP\\Files\\NotPermittedException",
      "Message":"Could not create folder \"/appdata_oc491gyqkd6i/preview/1/b/b/9/1/f/7/558\"",
...

Opening this issue is a followup to nextcloud/deck#5035 referenced in nextcloud/deck#5214.

---

I already did some debugging and the main issue occurs at the preview folder creation:

Where does the race condition occur?

It starts at

server/lib/private/Preview/Generator.php

Lines 594 to 605 in 43270c6

	private function getPreviewFolder(File $file) {
	// Obtain file id outside of try catch block to prevent the creation of an existing folder
	$fileId = (string)$file->getId();
	try {
	$folder = $this->appData->getFolder($fileId);
	} catch (NotFoundException $e) {
	$folder = $this->appData->newFolder($fileId);
	}
	return $folder;
	}

As both requests detect that the folder isn't there yet, both will attempt to create the new folder.
To my unterstanding from there it could go different routes dependent on the storage, for Deck it's the local storage.

Here's my debugging message and trace I got for the request that was slower on the local storage and therefore fails to create the new folder:

{ ...
   "url":"/core/preview?fileId=558&x=260&y=100&a=1",
   "message":"mkdir(): File exists at lib/private/Files/Storage/Local.php#110",
...}

#0 lib/private/Files/Storage/Wrapper/Wrapper.php(84): OC\Files\Storage\Local->mkdir('appdata_oc491gy...') 
#1 lib/private/Files/View.php(1148): OC\Files\Storage\Wrapper\Wrapper->mkdir('appdata_oc491gy...') 
#2 lib/private/Files/View.php(243): OC\Files\View->basicOperation('mkdir', '/appdata_oc491g...', Array) 
#3 lib/private/Files/Node/Folder.php(161): OC\Files\View->mkdir('/appdata_oc491g...') 
#4 lib/private/Files/AppData/AppData.php(149): OC\Files\Node\Folder->newFolder('1/b/b/9/1/f/7/5...') 
#5 lib/private/Preview/Storage/Root.php(74): OC\Files\AppData\AppData->newFolder('1/b/b/9/1/f/7/5...') 
#6 lib/private/Preview/Generator.php(643): OC\Preview\Storage\Root->newFolder('558') 
#7 lib/private/Preview/Generator.php(139): OC\Preview\Generator->getPreviewFolder(Object(OC\Files\Node\File)) 
...

(Please disregard line numbers, I inserted debugging output that might have shifted things)

What fails is mkdir on the local storage which could be fixed (the quick and dirty solution) by not failing the mkdir if the folder is already exisit:

server/lib/private/Files/Storage/Local.php

Line 114 in 43270c6

public function mkdir($path) {

	public function mkdir($path) {
		$sourcePath = $this->getSourcePath($path);
		$oldMask = umask($this->defUMask);
		$result = @mkdir($sourcePath, 0777, true);
		umask($oldMask);
+		if (is_dir($sourcePath)) { 
+			return true;
+		}
		return $result;
	}

Maybe a better solution would be to extend the error handling along the way at

server/lib/private/Files/Node/Folder.php

Lines 156 to 163 in efe68d0

	public function newFolder($path) {
	if ($this->checkPermissions(\OCP\Constants::PERMISSION_CREATE)) {
	$fullPath = $this->getFullPath($path);
	$nonExisting = new NonExistingFolder($this->root, $this->view, $fullPath);
	$this->sendHooks(['preWrite', 'preCreate'], [$nonExisting]);
	if (!$this->view->mkdir($fullPath)) {
	throw new NotPermittedException('Could not create folder "' . $fullPath . '"');
	}

This brings me to the misleading NotPermittedException

Why misleading exception?

That the mkdir failed does not necessarily mean that this was because of permissions as my debug output shows.
Maybe a GenericFileException would be more accurate instead? Something like:

	public function newFolder($path) {
		...
		if (!$this->view->mkdir($fullPath)) {
+			if (is_dir($fullPath)) { 
+				thow new AlreadyExistsException('Folder "' . $fullPath . '" already exists');
+			} else {
+				thow new GenericFileException('Could not create folder "' . $fullPath . '"');
+			}
		...

I'm a little unsure about this, but shouldn't "checkPermissions(\OCP\Constants::PERMISSION_CREATE)" have already checked whether we have sufficient permissions to create a subfolder?
And why is NonExistingFolder not checking that it is really non existing in its constructor?

Steps to reproduce

1. Upload a file e.g. an image without generating / requesting a preview
2. Send two preview request for that file simultaiously, e.g.:

GET /core/preview?fileId=123&x=260&y=100&a=1
GET /core/preview?fileId=123&x=64&y=64

Expected behavior

previews are generated regardless of concurrency

Installation method

Community Docker image

Nextcloud Server version

27

Operating system

Debian/Ubuntu

PHP engine version

PHP 8.1

Web server

Apache (supported)

Database engine version

SQlite

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

Fresh Nextcloud Server install

Are you using the Nextcloud Server Encryption module?

Encryption is Disabled

What user-backends are you using?

• Default user-backend (database)
• LDAP/ Active Directory
• SSO - SAML
• Other

Configuration report

No response

List of activated Apps

No response

Nextcloud Signing status

No response

Nextcloud Logs

No response

Additional info

No response

[solracsf]

Can't we add a \OCP\Lock\ILockingProvider::LOCK_EXCLUSIVE on the preview generation?

[jszeibert]

Can't we add a \OCP\Lock\ILockingProvider::LOCK_EXCLUSIVE on the preview generation?

As far as i understand, there is an exclusive lock on mkdir already?!

server/lib/private/Files/View.php

Line 244 in b2c0cd9

return $this->basicOperation('mkdir', $path, ['create', 'write']);

mkdir on the local storage is called with hooks ['create', 'write'], which should acquire a shared lock at first

server/lib/private/Files/View.php

Lines 1139 to 1142 in b2c0cd9

	if (in_array('write', $hooks) || in_array('delete', $hooks) || in_array('read', $hooks)) {
	// always a shared lock during pre-hooks so the hook can read the file
	$this->lockFile($path, ILockingProvider::LOCK_SHARED);
	}

and later changes that to an exclusive lock.

server/lib/private/Files/View.php

Lines 1148 to 1150 in b2c0cd9

	if (in_array('write', $hooks) || in_array('delete', $hooks)) {
	try {
	$this->changeLock($path, ILockingProvider::LOCK_EXCLUSIVE);

This however doesn't prevent that both requests attempt to create the same folder. For a lock to do so, I think it must be set in Preview/Generator.php::getPreviewFolder and this would collide with the lock later on.

Or was your intention to lock the file a preview was requested for?
I'm not sure this is a goot idea as this intails a lot of overhead e.g. when generating a lot of previews like with ./occ preview:generate-all

Wouldn't it be quicker to consider in mkdir that the folder might already exist for some reason and return the node to continue with the task that needed that folder?

[MrRinkana]

Am I understanding this correctly that this error can appear when the folder already exists? Or maybe only if its creation is attempted shortly after its created?

An instance I'm administering is getting the same errors, but without deck being installed. In my case the errors appear when imaginary is getting to generate thumbnails, mainly when users are scrolling newly added pictures in the memories app.

Example error:

NotPermittedException Could not create folder "/appdata_ocfipsbj1v0e/preview/5/8/9/f/7/6/3/7208"

{
  "reqId": "qziGBcbIZyDSvjrtowZu",
  "level": 3,
  "time": "2024-05-06T21:19:53+00:00",
  "remoteAddr": "193.138.218.201",
  "user": "nMax",
  "app": "index",
  "method": "GET",
  "url": "/apps/photos/api/v1/preview/7208?etag=98554f85f4bdf99d151b69b277f80d50&x=512&y=512",
  "message": "Could not create folder \"/appdata_ocfipsbj1v0e/preview/5/8/9/f/7/6/3/7208\"",
  "userAgent": "Mozilla/5.0 (X11; Linux x86_64; rv:125.0) Gecko/20100101 Firefox/125.0",
  "version": "28.0.5.1",
  "exception": {
    "Exception": "OCP\\Files\\NotPermittedException",
    "Message": "Could not create folder \"/appdata_ocfipsbj1v0e/preview/5/8/9/f/7/6/3/7208\"",
    "Code": 0,
    "Trace": [
      {
        "file": "/srv/www/nextcloud/lib/private/Files/AppData/AppData.php",
        "line": 147,
        "function": "newFolder",
        "class": "OC\\Files\\Node\\Folder",
        "type": "->"
      },
      {
        "file": "/srv/www/nextcloud/lib/private/Preview/Storage/Root.php",
        "line": 74,
        "function": "newFolder",
        "class": "OC\\Files\\AppData\\AppData",
        "type": "->"
      },
      {
        "file": "/srv/www/nextcloud/lib/private/Preview/Generator.php",
        "line": 607,
        "function": "newFolder",
        "class": "OC\\Preview\\Storage\\Root",
        "type": "->"
      },
      {
        "file": "/srv/www/nextcloud/lib/private/Preview/Generator.php",
        "line": 133,
        "function": "getPreviewFolder",
        "class": "OC\\Preview\\Generator",
        "type": "->"
      },
      {
        "file": "/srv/www/nextcloud/lib/private/Preview/Generator.php",
        "line": 110,
        "function": "generatePreviews",
        "class": "OC\\Preview\\Generator",
        "type": "->"
      },
      {
        "file": "/srv/www/nextcloud/lib/private/PreviewManager.php",
        "line": 187,
        "function": "getPreview",
        "class": "OC\\Preview\\Generator",
        "type": "->"
      },
      {
        "file": "/srv/www/nextcloud/apps/photos/lib/Controller/PreviewController.php",
        "line": 178,
        "function": "getPreview",
        "class": "OC\\PreviewManager",
        "type": "->"
      },
      {
        "file": "/srv/www/nextcloud/apps/photos/lib/Controller/PreviewController.php",
        "line": 144,
        "function": "fetchPreview",
        "class": "OCA\\Photos\\Controller\\PreviewController",
        "type": "->"
      },
      {
        "file": "/srv/www/nextcloud/lib/private/AppFramework/Http/Dispatcher.php",
        "line": 230,
        "function": "index",
        "class": "OCA\\Photos\\Controller\\PreviewController",
        "type": "->"
      },
      {
        "file": "/srv/www/nextcloud/lib/private/AppFramework/Http/Dispatcher.php",
        "line": 137,
        "function": "executeController",
        "class": "OC\\AppFramework\\Http\\Dispatcher",
        "type": "->"
      },
      {
        "file": "/srv/www/nextcloud/lib/private/AppFramework/App.php",
        "line": 184,
        "function": "dispatch",
        "class": "OC\\AppFramework\\Http\\Dispatcher",
        "type": "->"
      },
      {
        "file": "/srv/www/nextcloud/lib/private/Route/Router.php",
        "line": 315,
        "function": "main",
        "class": "OC\\AppFramework\\App",
        "type": "::"
      },
      {
        "file": "/srv/www/nextcloud/lib/base.php",
        "line": 1069,
        "function": "match",
        "class": "OC\\Route\\Router",
        "type": "->"
      },
      {
        "file": "/srv/www/nextcloud/index.php",
        "line": 39,
        "function": "handleRequest",
        "class": "OC",
        "type": "::"
      }
    ],
    "File": "/srv/www/nextcloud/lib/private/Files/Node/Folder.php",
    "Line": 162,
    "message": "Could not create folder \"/appdata_ocfipsbj1v0e/preview/5/8/9/f/7/6/3/7208\"",
    "exception": [],
    "CustomMessage": "Could not create folder \"/appdata_ocfipsbj1v0e/preview/5/8/9/f/7/6/3/7208\""
  },
  "id": "66408f0280dc8"
}

Nextcloud 28.0.5

[joshtrichards]

Fixed in #45313 (based on #44507).