OCP\Lock\LockedException during files:scan #24507

Closed
morodin opened this Issue May 9, 2016 · 25 comments

Projects

None yet

5 participants

@morodin
morodin commented May 9, 2016

Steps to reproduce

  1. Starting file scan: php console.php files:scan all

Expected behaviour

Scan finishes.

Actual behaviour

The scan is stopped with the following exception:

  [OCP\Lock\LockedException]
  "files/e2d61478e39c7ca55b79526151165f30" is locked

files:scan [-p|--path="..."] [-q|--quiet] [--all] [user_id1] ... [user_idN]

The user has no files at all, there might be a shared file with this user.
We found similar problems, tried the solution suggested, like setting the service in maintenance mode and clearing the file_locks table, but without success.

I'm quite sure that the data i can provide is not enough to analyse this issue and would be more than happy to do additional tests.

Server configuration

Operating system: CentOS release 6.7
Web server: Apache/2.2.15
Database: mysql 5.1.73
PHP version: PHP 5.6.20
ownCloud version: 8.2.4
Updated from older install, all the way up from 6.x.
Where did you install ownCloud from:
Installed form tar archive.

Settings page reports "All checks passed".

List of activated apps:
Enabled:

  • files: 1.2.1
  • files_pdfviewer: 0.7.1
  • files_sharing: 0.7.0
  • files_texteditor: 2.0
  • files_trashbin: 0.7.0
  • files_versions: 1.1.0
  • files_videoviewer: 0.1.3
  • firstrunwizard: 1.1
  • gallery: 14.2.0
  • notifications: 0.1.0
  • updater: 0.6
  • user_ldap: 0.7.1

Disabled:

  • activity
  • bookmarks
  • calendar
  • contacts
  • documents
  • encryption
  • external
  • files_external
  • mozilla_sync
  • news
  • provisioning_api
  • templateeditor
  • user_external

The content of config/config.php:

$CONFIG = array (
  'instanceid' => 'xx',
  'passwordsalt' => 'xx',
  'datadirectory' => '/export/owncloud-data',
  'dbtype' => 'mysql',
  'dbname' => 'owncloud',
  'dbhost' => 'localhost',
  'dbtableprefix' => 'oc_',
  'dbuser' => 'owncloud',
  'dbpassword' => 'xx',
  'installed' => true,
  'loglevel' => 2,
  'log_rotate_size' => '104857600',
  'ldapIgnoreNamingRules' => false,
  'forcessl' => true,
  'theme' => '',
  'maintenance' => false,
  'memcache.local' => '\\OC\\Memcache\\APCu',
  'preview_libreoffice_path' => '/usr/bin/libreoffice',
  'enable_previews' => true,
  'trusted_domains' =>
  array (
    0 => 'xx.example.domain.com',
  ),
  'mail_smtpmode' => 'smtp',
  'mail_from_address' => 'owncloud',
  'mail_domain' => 'exampe.domain.com',
  'mail_smtphost' => '127.0.0.1',
  'mail_smtpport' => '25',
  'version' => '8.2.4.2',
  'secret' => 'xx',
  'trashbin_retention_obligation' => 'auto',
);

Are you using external storage, if yes which one:
no

Are you using encryption:
no

Are you using an external user-backend, if yes which one:
ActiveDirectory

LDAP configuration (delete this part if not used)

+-------------------------------+------------------------------------------------------------------------------+
| Configuration                 | s01                                                                          |
+-------------------------------+------------------------------------------------------------------------------+
| hasMemberOfFilterSupport      | 1                                                                            |
| hasPagedResultSupport         |                                                                              |
| homeFolderNamingRule          |                                                                              |
| lastJpegPhotoLookup           | 0                                                                            |
| ldapAgentName                 | cn=someuser,ou=someou,dc=example,dc=com                           |
| ldapAgentPassword             | ***                                                                          |
| ldapAttributesForGroupSearch  |                                                                              |
| ldapAttributesForUserSearch   |                                                                              |
| ldapBackupHost                | ldap://dc.example.com                                            |
| ldapBackupPort                | 389                                                                          |
| ldapBase                      | dc=example,dc=com                                                 |
| ldapBaseGroups                | dc=example,dc=com                                                 |
| ldapBaseUsers                 | dc=example,dc=com                                                 |
| ldapCacheTTL                  | 600                                                                          |
| ldapConfigurationActive       | 1                                                                            |
| ldapEmailAttribute            | mail                                                                         |
| ldapExperiencedAdmin          | 0                                                                            |
| ldapExpertUUIDGroupAttr       |                                                                              |
| ldapExpertUUIDUserAttr        |                                                                              |
| ldapExpertUsernameAttr        |                                                                              |
| ldapGroupDisplayName          | cn                                                                           |
| ldapGroupFilter               | (&(|(objectclass=group)))                                                    |
| ldapGroupFilterGroups         |                                                                              |
| ldapGroupFilterMode           | 0                                                                            |
| ldapGroupFilterObjectclass    | group                                                                        |
| ldapGroupMemberAssocAttr      | member                                                                       |
| ldapHost                      | ldap://ldap.example.com
| ldapIgnoreNamingRules         |                                                                              |
| ldapLoginFilter               | (&(&(|(l=xx)(l=yy))(objectclass=user))(samaccountname=%uid)) |
| ldapLoginFilterAttributes     |                                                                              |
| ldapLoginFilterEmail          | 0                                                                            |
| ldapLoginFilterMode           | 0                                                                            |
| ldapLoginFilterUsername       | 1                                                                            |
| ldapNestedGroups              | 0                                                                            |
| ldapOverrideMainServer        | 0                                                                            |
| ldapPagingSize                | 500                                                                          |
| ldapPort                      | 389                                                                          |
| ldapQuotaAttribute            |                                                                              |
| ldapQuotaDefault              |                                                                              |
| ldapTLS                       | 1                                                                            |
| ldapUserDisplayName           | displayname                                                                  |
| ldapUserDisplayName2          |                                                                              |
| ldapUserFilter                | (&(|(l=xx)(l=yy))(objectclass=user))                         |
| ldapUserFilterGroups          |                                                                              |
| ldapUserFilterMode            | 1                                                                            |
| ldapUserFilterObjectclass     | person                                                                       |
| ldapUuidGroupAttribute        | auto                                                                         |
| ldapUuidUserAttribute         | auto                                                                         |
| turnOffCertCheck              | 1                                                                            |
| useMemberOfToDetectMembership | 1                                                                            |
+-------------------------------+------------------------------------------------------------------------------+

Client configuration

Browser: n.a.a
Operating system:

Logs

Web server error log

nothing relevant here

ownCloud log (data/owncloud.log)

no entry during the scan at all

@PVince81
Collaborator

Did you try adding --:

Before: php console.php files:scan all
After: php console.php files:scan --all

The syntax you used would try and scan files for a user called "all".

@PVince81
Collaborator

The output you posted does look like you used the wrong syntax.
Still, it's weird that it would show a LockedException in this case.

CC @icewind1991

@morodin
morodin commented May 10, 2016

I did use the correct syntax. I even got the a user list and called the scan for each user. I still get the error for some users.

@PVince81
Collaborator

Does the scanner abort after the error or continues scanning ?
It is also likely that the folders were really in use by users, so they were locked.

But if it's always the same ones during each scan, maybe there are stray locks in the database.
In this case, plan a maintenance window and in that time, enable maintenance mode, then delete * from oc_file_locks, disable maintenance mode.

@morodin
morodin commented May 10, 2016

It is always the same one. And, as I wrote, did the 'enable maintenance mode, delete * from oc_file_locks, disable maintenance mode'. Starting the scan populates the oc_file_locks table again and the scan stops at exactly the same point.

@PVince81
Collaborator

Do you happen to have any symlinks in your folder structure ?

@morodin
morodin commented May 10, 2016

If you mean the owncloud data directory, no. The only symlink I have is from /export/owncloud to /export/owncloud-8.2.4.

@d3vm4t
d3vm4t commented May 13, 2016 edited

I faced the same issue after upgrading from version 8.2.3 to 8.2.4. After the upgrade I tried to scan the files with php occ files:scan --all and ran into the mentioned exception:

[OCP\Lock\LockedException]
"files/xxx" is locked

files:scan [-p|--path="..."] [-q|--quiet] [--all] [user_id1] ... [user_idN]

Then I have cleared everything in the oc_file_locks table but after doing a scan with files:scan --all the table was filled with the same content again and the scan stopped at same position with the same exception. Clearing the oc_file_cache table and doing another scan led to the same problem.
Nothing useful in the logs... I could not find a solution. Therefore I rolled the installation back to my 8.2.3 backup but kept the database and files of 8.2.4 so I can give further information about this case. But I don't really know which information might be helpful.
I have nearly the same configuration as morodin. The owncloud installation is on a shared hosting server with Apache/2.4.10 and PHP Version 5.6.12. I have only apps enabled that are enabled by default so there is actually nothing special with the installation. With owncloud 6 up to 8.2.3 everything was/is fine with it. I only get the exception mentioned above with 8.2.4. I have installed 8.2.4 from zip archive. The md5 sum was correct.
Please let me know which information might be helpful to specify the problem.

Edit: Of course, I meant php occ files:scan --all instead of php occ files:scan -all.

@PVince81
Collaborator

@d3vm4t thanks for the info.

@icewind1991 would be good to have a way to get more debug info about locks in a productive environment, at least to find out which file is affected by the stray lock.

@PVince81 PVince81 added this to the 8.2.6-current-maintenance milestone May 17, 2016
@PVince81
Collaborator

@d3vm4t when you say "everything was fine with 8.2.3", do you mean that "occ files:scan --all" does not stop at the lock ? This could be an important clue as we can find out what changed in the code between the versions and could possibly cause this issue.

@morodin
morodin commented May 17, 2016

For me, this issue existed with 8.2.2 as well. And i would second the comment about getting info which file is causing the lock. Do you have any way that we can go now to find out, which file it is?

@d3vm4t
d3vm4t commented May 17, 2016

@PVince81 Exactly. With 8.2.3 "occ files:scan --all" doesn't stop. Every single scan with file:scan runs well in 8.2.3.
For 8.2.4: When I delete the line named in the exception "files/xxx" is locked in the oc_file_locks table (because of the length of "xxx" (32 characters) I think this could be the md5 sum of the file) the scan stops at another file. The interesting thing is that the table is fully restored after the scan (same when I clear the full table) so the next scan will stop at the original file of the first scan. Therefore I am convinced that the issue is associated with a change that was made between the versions.

@PVince81
Collaborator

This patch would log the file names before they got converted to MD5:

diff --git a/lib/private/files/storage/common.php b/lib/private/files/storage/common.php
index 5a15e25..ef11305 100644
--- a/lib/private/files/storage/common.php
+++ b/lib/private/files/storage/common.php
@@ -632,6 +632,7 @@ abstract class Common implements Storage {
         * @throws \OCP\Lock\LockedException
         */
        public function acquireLock($path, $type, ILockingProvider $provider) {
+               \OC::$server->getLogger()->debug('acquireLock $path="' . $path . '" $type="' . $type . '"', array('app' => 'LOCKING'));
                $provider->acquireLock('files/' . md5($this->getId() . '::' . trim($path, '/')), $type);
        }

@@ -641,6 +642,7 @@ abstract class Common implements Storage {
         * @param \OCP\Lock\ILockingProvider $provider
         */
        public function releaseLock($path, $type, ILockingProvider $provider) {
+               \OC::$server->getLogger()->debug('releaseLock $path="' . $path . '" $type="' . $type . '"', array('app' => 'LOCKING'));
                $provider->releaseLock('files/' . md5($this->getId() . '::' . trim($path, '/')), $type);
        }

@@ -650,6 +652,7 @@ abstract class Common implements Storage {
         * @param \OCP\Lock\ILockingProvider $provider
         */
        public function changeLock($path, $type, ILockingProvider $provider) {
+               \OC::$server->getLogger()->debug('changeLock $path="' . $path . '" $type="' . $type . '"', array('app' => 'LOCKING'));
                $provider->changeLock('files/' . md5($this->getId() . '::' . trim($path, '/')), $type);
        }

you need to have "loglevel => 0" in your config.php for the messages to appear.
Beware, it can log a LOT if there's a lot of activity on your instance.

Then when running the scan you might see one acquireLock that failed, possibly the last entry in the log.

@morodin
morodin commented May 17, 2016

We integrated that patch. And got a little bit of a result:

When we scan user x, we get the exception. The file mentioned in the log message is from user y and is shared with user x.
When we scan user y, we get the exception as well. The file mentioned for user y is a file from user x, shared with user y.

I hope this is understandable.

@PVince81
Collaborator

@morodin thanks for the info. So it would mean that simply sharing a file from a user y with another user x, and then scanning with user x would already trigger the lock error ?
Do you have more info about the share type ? User share vs group share ? Is the file shared directly or is one of the parent folders shared ?

@morodin
morodin commented May 17, 2016

In both cases, its files that are shared, not folders.
In one case, the file is shared just between the two users. In the other case, it is shared among more users, but without any group involvement.

@PVince81
Collaborator

Ha, gotcha. It's a single file share.
Folder share works fine.

Steps

  1. Create two users "user1" and "user2"
  2. Login as "user1"
  3. Create/upload a file "bacon.txt" into "test"
  4. Share "bacon.txt" with "user2"
  5. Login as "user2", see that the file is there
  6. On the CLI: "occ files:scan user2"

💣 LockedException

Thanks for the info! Let's bisect this regression...

@PVince81 PVince81 added the regression label May 17, 2016
@PVince81
Collaborator

And here we go, this is breaking commit: fd8e3f7 from PR #24260 @icewind1991

@PVince81
Collaborator

It seems to work fine in v9.0.2.

So maybe there is something in the 8.2 specific code that is triggering this issue, possibly the way how sharing works. Note that sharing has been reworked in 9.0.2.

@PVince81
Collaborator

Just retried on stable8.2 and the problem still exists.

@icewind1991 please have a look, see steps here #24507 (comment)

@PVince81 PVince81 added the sev2-high label Jun 13, 2016
@PVince81
Collaborator

Problem did not exist in 8.1. Fixed in 8.2.6.

@PVince81 PVince81 closed this Jun 16, 2016
@crysman
crysman commented Jun 24, 2016

I've had the same issue.
I've been able to run php occ files:scan --all without any errors with LOCK after I disabled the Share Files 0.7.0 plugin.

BUT, after I enabled the plugin again, the issue is back :/ There is something wrong... And according to what I am reporting here, it is primarily connected to that plugin.

I've updated today to 8.2.5 (8.2.5.2), I do not know if it worked before the update, though :/

@PVince81
Collaborator

Fixed in 8.2.6.

If you like you could try with 8.2.6 RC1

@crysman
crysman commented Jun 24, 2016

If its fixed in 2.6, I'll wait for non-rc public version and instll it via standard Debian repo, thanks!

@crysman
crysman commented Jan 2, 2017

I've just tried it in 9.1.2 and it runs and ends correctly except some exceptions thrown just by some users.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment