Owncloud deletes in the database all Dropbox files if external_files app is blocked/limited #24739

Closed
faulix opened this Issue May 20, 2016 · 17 comments

Projects

None yet

3 participants

@faulix
faulix commented May 20, 2016 edited

Steps to reproduce

  1. Have big Dropbox account connected (about 10GB) with many different files
  2. Use Mac OS X desktop client to synchronize
  3. Let a cron run in background

Expected behaviour

Nothing should happen

Actual behaviour

Owncloud blocks the files_external app because of too many connections. The cron seems to check the database and deletes the Dropbox files as it can't double-check them (files_external app is blocked). The desktop client of course detects that immediately and deletes all local files, which is a quite massive impact as I need to download again 10GB.

Note: The cron behavior is guessed but sounds logic according the result. I also got several mails at that time that a cron-job couldn't get executed as a cron is already running.

Server configuration

Operating system: Debian 8, Linux version 3.16.0-4-amd64

Web server: Apache/2.4.10
Database: mysql 5.5.49-0+deb8u1
PHP version: PHP 5.6.20-0+deb8u1
ownCloud version: 9.0.2 (stable)
Updated from an older ownCloud or fresh install: Fresh install
Where did you install ownCloud from: Package manager (APT)
Signing status (ownCloud 9.0 and above): No errors have been found.
List of activated apps:

Enabled:
  - activity: 2.2.1
  - calendar: 1.1
  - comments: 0.2
  - contacts: 1.2.0.0
  - dav: 0.1.6
  - federatedfilesharing: 0.1.0
  - files: 1.4.4
  - files_external: 0.5.2
  - files_pdfviewer: 0.8.1
  - files_sharing: 0.9.1
  - files_texteditor: 2.1
  - files_trashbin: 0.8.0
  - files_versions: 1.2.0
  - files_videoplayer: 0.9.8
  - firstrunwizard: 1.1
  - gallery: 14.5.0
  - notifications: 0.2.3
  - provisioning_api: 0.4.1
  - systemtags: 0.2
  - templateeditor: 0.1
  - updatenotification: 0.1.0
Disabled:
  - encryption
  - external
  - federation
  - files_antivirus
  - user_external
  - user_ldap

The content of config/config.php:

{
    "system": {
        "updatechecker": false,
        "instanceid": "ocrjwhl0os72",
        "passwordsalt": "***REMOVED SENSITIVE VALUE***",
        "secret": "***REMOVED SENSITIVE VALUE***",
        "trusted_domains": [
            "stefankuhn.biz"
        ],
        "datadirectory": "\/var\/www\/owncloud\/data",
        "overwrite.cli.url": "https:\/\/mydomain.biz\/owncloud",
        "dbtype": "mysql",
        "version": "9.0.2.2",
        "dbname": "c4_owncloud",
        "dbhost": "localhost",
        "dbtableprefix": "oc_",
        "dbuser": "***REMOVED SENSITIVE VALUE***",
        "dbpassword": "***REMOVED SENSITIVE VALUE***",
        "logtimezone": "UTC",
        "installed": true,
        "mail_smtpmode": "php",
        "mail_smtpsecure": "ssl",
        "mail_from_address": "owncloud",
        "mail_domain": "mydomain.biz",
        "mail_smtphost": "mail.mydomain.biz",
        "mail_smtpport": "587",
        "mail_smtpauth": 1
    }
}

Are you using external storage, if yes which one: Dropbox
Are you using encryption: no
Are you using an external user-backend, if yes which one: No

Client configuration

Browser: Google Chrome Version 50.0.2661.94 (64-bit)
Operating system: Mac OS X 10.10.5 (14F1713)

Logs

Web server error log

Nothing

ownCloud log (data/owncloud.log)

{
    "reqId": "khI3eGIPPFRoLZoQAGtM",
    "remoteAddr": "",
    "app": "files_external",
    "message": "Forbidden. Your app is making too many requests and is being rate limited. 503s can trigger on a per-app or per-user basis.",
    "level": 3,
    "time": "2016-05-19T15:19:20+00:00",
    "method": "--",
    "url": "--",
    "user": "--"
}{
    "reqId": "YFwthDeIOoyf12SWypGT",
    "remoteAddr": "27.34.250.230",
    "app": "files_external",
    "message": "Forbidden. Your app is making too many requests and is being rate limited. 503s can trigger on a per-app or per-user basis.",
    "level": 3,
    "time": "2016-05-19T15:19:23+00:00",
    "method": "PROPFIND",
    "url": "\/owncloud\/remote.php\/webdav\/Dropbox-Privat\/private_file",
    "user": "stefan"
}{
    "reqId": "khI3eGIPPFRoLZoQAGtM",
    "remoteAddr": "",
    "app": "files_external",
    "message": "Forbidden. Your app is making too many requests and is being rate limited. 503s can trigger on a per-app or per-user basis.",
    "level": 3,
    "time": "2016-05-19T15:26:23+00:00",
    "method": "--",
    "url": "--",
    "user": "--"
}{
    "reqId": "khI3eGIPPFRoLZoQAGtM",
    "remoteAddr": "",
    "app": "files_external",
    "message": "Server error. The server has either erred or is incapable of performing the requested operation.",
    "level": 3,
    "time": "2016-05-19T16:05:11+00:00",
    "method": "--",
    "url": "--",
    "user": "--"
}{
    "reqId": "W+HGDo\/T5cIjv8hbVEhu",
    "remoteAddr": "27.34.250.230",
    "app": "files_external",
    "message": "Forbidden. Your app is making too many requests and is being rate limited. 503s can trigger on a per-app or per-user basis.",
    "level": 3,
    "time": "2016-05-19T16:05:16+00:00",
    "method": "PROPFIND",
    "url": "\/owncloud\/remote.php\/webdav\/Dropbox-Privat\/private_file",
    "user": "stefan"
}{
    "reqId": "jQD2JDWcRdM8D6Z+Kiei",
    "remoteAddr": "27.34.250.230",
    "app": "files_external",
    "message": "Forbidden. Your app is making too many requests and is being rate limited. 503s can trigger on a per-app or per-user basis.",
    "level": 3,
    "time": "2016-05-19T16:05:18+00:00",
    "method": "PROPFIND",
    "url": "\/owncloud\/remote.php\/webdav\/Dropbox-Privat\/private_file",
    "user": "stefan"
}{
    "reqId": "khI3eGIPPFRoLZoQAGtM",
    "remoteAddr": "",
    "app": "files_external",
    "message": "Forbidden. Your app is making too many requests and is being rate limited. 503s can trigger on a per-app or per-user basis.",
    "level": 3,
    "time": "2016-05-19T16:31:30+00:00",
    "method": "--",
    "url": "--",
    "user": "--"
}
@PVince81
Collaborator

It's not ownCloud that blocks it, it's Dropbox that limits the number of connections. ownCloud is making too many connections to Dropbox.

Hmm, can you check the oc_filecache table ? There is probably a problem in the error handling logic that makes it believe that the folders are empty instead of bailing out.

@PVince81
Collaborator

And you mentionned cron, so it's probably the background scan that checks for updates

@PVince81 PVince81 added this to the 9.0.3-current-maintenance milestone May 20, 2016
@PVince81
Collaborator
@faulix
faulix commented May 20, 2016

@PVince81 interesting fact: The desktop client warned me that a huge amount of files got deleted and asked whether the files should get deleted or not. I pressed no and closed the desktop client (had similar problem already before). On the next morning I started the desktop client again and everything was fine, nothing to delete/download. So I assume the background-scan added the files later again when it could connect to Dropbox again.

@Xenopathic
Member

The Dropbox storage backend needs to throw StorageNotAvailableException (or a subclass of that so that the web UI understands it's a temporary situation), so the storage will be marked as unavailable and given a 10 minute cooling off period. Also, files won't be deleted in this circumstance.

@PVince81
Collaborator

Indeed, that's the best approach. I had a quick look at the code but couldn't identify which code path would cause the scanner to think the folder is empty.
opendir would return false in case of error, not an empty array.

@faulix
faulix commented May 20, 2016 edited

Why the scanner needs to think the folder is empty, isn't it enough to get false that the scanner thinks the directory doesn't exist anymore and deletes it from the database?

@PVince81
Collaborator

Not sure. I'd expect false to be understood as "don't go there", but maybe there's a piece of buggy code that interprets "false" like an empty array. Need to do some debugging to find the code path in question.

@faulix
faulix commented May 20, 2016

Currently this operation will throw Dropbox_Exception_Forbidden, which should be enough to identify clearly that Dropbox is not available (not existing would be Dropbox_Exception_NotFound).

Where can I find the scan-methods, then I can also have a look, because right now I can't find them.

@PVince81
Collaborator

If you have a debugger, you can try adding a breakpoint in dropbox.php in the hasUpdated method. It is usually called before the scanner does anything. If that method returns true, it means it has to check the child elements to find the changes.

@faulix
faulix commented May 20, 2016

No, I didn't load/install OC locally and I installed it only on my server. I will still have a look ;)

@faulix
faulix commented May 20, 2016

I think I identified the problem:
The deletion is called in the method scanFile in lib/private/files/cache/scanner.php.
In line 142-220 we have the following:

            $data = $this->getData($file);
            if ($data) {
                [...]
            } else {
                $this->removeFromCache($file);
            }

So if $data is NULL or FALSE, then the file will be deleted.

Now let's have a look into getData:

    protected function getData($path) {
        $data = $this->storage->getMetaData($path);
        if (is_null($data)) {
            \OCP\Util::writeLog('OC\Files\Cache\Scanner', "!!! Path '$path' is not accessible or present !!!", \OCP\Util::DEBUG);
        }
        return $data;
    }

This will use getMetaData in apps/files_external/3rdparty/Dropbox/API.php:

public function getMetaData($path, $list = true, $hash = null, $fileLimit = null, $root = null) {
        [...]
        /* 304 is not modified */
        if ($response['httpStatus']==304) {
            return true;
        } else {
            return json_decode($response['body'],true);
        }
    }

The problem is, that $response is empty as we got a 503 exception, let's have a look into apps/files_external/3rdparty/Dropbox/OAuth/PHP.php:

                case 503 : 
                    throw new Dropbox_Exception_Forbidden('Forbidden. Your app is making too many requests and is being rate limited. 503s can trigger on a per-app or per-user basis.');

There is no return.

Now to follow up the chain backwards:

  1. OAuth returns nothing (file PHP.php)
  2. $response is null (API.php)
  3. json_decode returns NULL (API.php)
  4. $data in getData is null (Scanner.php)
  5. $data in scanFile is null (Scanner.php)
  6. Deletion of file in else clause of scanFile (Scanner.php)

Potential fix:
I think we need to add a chain of Exceptions (API.php and Scanner.php) and then pause the storage and don't delete as long as the storage is marked as unavailable.

Problem:
We need to change an external package (Dropbox).

@PVince81
Collaborator

Awesome analysis @faulix.

At some point we do need to upgrade or swap the Dropbox library for a better one as this one is outdated / unmaintained.

In the meantime, I super-dirty fix would be to catch "Dropbox_Exception_Forbidden" in getMetadata. However, it might be a legitimate 403 exception instead of 503. So the idea would be to call the exception's getMessage and see whether it contains the string about rate limit. Extremely ugly but would do the job. When this case occurs, throw StorageNotAvailableException. This should make the scanner give up with this storage.

@faulix
faulix commented May 23, 2016

The problem is that Dropbox released the new API (V2) in April and there is no official PHP SDK so far neither well developed projects on Github. So most probably we should solve that in a dirty way and wait until there is something available for the V2 API.

@PVince81
Collaborator

Good to know, thanks for the research.

But maybe there's another better SDK for version V1. On the other hand, if a lot of work needs to be done just for the upgrade, better do it directly for the latest version.

I agree, dirty hack it will have to be short-term.

@PVince81
Collaborator

I had another look at the different "Forbidden" responses. They all look like there is something wrong with the request and have nothing to do with access control on files. Some are even about expired tokens or server errors.

This means that we should simply catch any Dropbox Forbidden exception and convert them to StorageNotAvailableException or so. Returning false there is very bad because it would cause opendir or stat to believe the file/folder does not exist at all.

@PVince81
Collaborator

Fix is here #25104

@guruz guruz changed the title from Owncloud deletes in the database all external storage files if external_files app is blocked/limited to Owncloud deletes in the database all Dropbox files if external_files app is blocked/limited Jun 15, 2016
@PVince81 PVince81 closed this in #25104 Jun 16, 2016
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment