Postgres duplicate key violation causes Internal Server Error during sync

[linuxrrze]

Steps to reproduce

1. Use postgresql as database backend
2. have a lot of files (I suppose this is not required, but helps to trigger the problem, in my case > 100.000 files, > 100 GB)
3. Setup a new nextcloud client and start to sync

Expected behaviour

All data should be synced to the client without error/warning

Actual behaviour

After some files (number varies) the sync stops with "server replied: Internal Server Error"

Server configuration

Operating system:
Ubuntu 16.04

Web server:
Apache 2.4.18

Database:
Postgres 9.5.6

PHP version:
php 7.0.15

Nextcloud version: (see Nextcloud admin page)

11.0.3

Updated from an older Nextcloud/ownCloud or fresh install:

Updated

Where did you install Nextcloud from:

https://download.nextcloud.com/server/releases/nextcloud-11.0.3.tar.bz2

Signing status:

Signing status

plain 11.0.3 with github patch:
e47d8028dcb26dc50fe61f8e08e0c2c5a8054dc2
(this solves other sync related problems)

List of activated apps:

App list

Enabled:
  - activity: 2.4.1
  - admin_audit: 1.1.0
  - admin_notifications: 1.0.0
  - announcementcenter: 3.0.0
  - apporder: 0.3.3
  - audioplayer: 1.5.1
  - bookmarks: 0.9.1
  - calendar: 1.5.2
  - comments: 1.1.0
  - contacts: 1.5.3
  - dav: 1.1.1
  - direct_menu: 0.10.1
  - federatedfilesharing: 1.1.1
  - federation: 1.1.1
  - files: 1.6.1
  - files_accesscontrol: 1.1.2
  - files_downloadactivity: 1.0.1
  - files_markdown: 1.0.1
  - files_pdfviewer: 1.0.1
  - files_reader: 1.0.4
  - files_retention: 1.0.1
  - files_sharing: 1.1.1
  - files_texteditor: 2.2
  - files_trashbin: 1.1.0
  - files_versions: 1.4.0
  - files_videoplayer: 1.0.0
  - gallery: 16.0.0
  - keeweb: 0.3.1
  - logreader: 2.0.0
  - lookup_server_connector: 1.0.0
  - news: 10.2.0
  - nextant: 1.0.8
  - nextcloud_announcements: 1.0
  - notes: 2.2.0
  - notifications: 1.0.1
  - onlyoffice: 1.0.2
  - password_policy: 1.1.0
  - previewgenerator: 1.0.5
  - provisioning_api: 1.1.0
  - serverinfo: 1.1.1
  - sharebymail: 1.0.1
  - spreed: 1.2.0
  - systemtags: 1.1.3
  - tasks: 0.9.5
  - templateeditor: 0.2
  - theming: 1.1.1
  - twofactor_backupcodes: 1.0.0
  - updatenotification: 1.1.1
  - user_ldap: 1.1.2
  - weather: 1.3.5
  - workflowengine: 1.1.1
Disabled:
  - encryption
  - external
  - files_automatedtagging
  - files_external
  - firstrunwizard
  - registration
  - survey_client
  - user_external
  - user_saml

Nextcloud configuration:

Config report

<?php
$CONFIG = array (
  'instanceid' => 'oc8a028e04ae',
  'passwordsalt' => 'PASSWORDSALT',
  'datadirectory' => '/proj.stand/web/nextcloud.data',
  'dbtype' => 'pgsql',
  'version' => '11.0.3.2',
  'installed' => true,
  'ldapIgnoreNamingRules' => false,
  'forcessl' => true,
  'loglevel' => 0,
  'theme' => '',
  'overwrite.cli.url' => '/nextcloud',
  'maintenance' => false,
  'enable_previews' => true,
  'preview_max_x' => NULL,
  'preview_max_y' => NULL,
  'preview_max_scale_factor' => 10,
  'preview_libreoffice_path' => '/usr/bin/libreoffice',
  'enabledPreviewProviders' => 
  array (
    0 => 'OC\\Preview\\Image',
    1 => 'OC\\Preview\\MP3',
    2 => 'OC\\Preview\\TXT',
    3 => 'OC\\Preview\\MarkDown',
    4 => 'OC\\Preview\\Illustrator',
    5 => 'OC\\Preview\\Movie',
    6 => 'OC\\Preview\\MSOffice2003',
    7 => 'OC\\Preview\\MSOffice2007',
    8 => 'OC\\Preview\\MSOfficeDoc',
    9 => 'OC\\Preview\\OpenDocument',
    10 => 'OC\\Preview\\PDF',
    11 => 'OC\\Preview\\PhotoShop',
    12 => 'OC\\Preview\\Postscript',
    13 => 'OC\\Preview\\StarOffice',
    14 => 'OC\\Preview\\SVG',
    15 => 'OC\\Preview\\Font',
  ),
  'trusted_domains' => 
  array (
    0 => 'www.meins.de',
  ),
  'secret' => 'VERYLONGSECRET',
  'trashbin_retention_obligation' => 'auto',
  'memcache.local' => '\\OC\\Memcache\\APCu',
  'dbname' => 'nextcloud',
  'dbhost' => 'localhost',
  'dbuser' => 'nextcloud',
  'dbpassword' => 'wlf9ajzi61zg9lfb',
  'updater.release.channel' => 'stable',
  'ldapProviderFactory' => '\\OCA\\User_LDAP\\LDAPProviderFactory',
  'logtimezone' => 'Europe/Berlin',
  'lost_password_link' => 'https://www.meins.de/selfservice',
  'auth.bruteforce.protection.enabled' => true,
  'knowledgebaseenabled' => true,
  'enable_avatars' => true,
  'redis' => 
  array (
    'port' => '6379',
    'host' => '127.0.0.1',
    'timeout' => '0',
  ),
  'memcache.locking' => '\\OC\\Memcache\\Redis',
  'filelocking.enabled' => true,
);

Are you using external storage, if yes which one: local/smb/sftp/...

NO

Are you using encryption: yes/no

NO

Are you using an external user-backend, if yes which one: LDAP/ActiveDirectory/Webdav/...

YES: LDAP (Samba DC)

LDAP configuration (delete this part if not used)

LDAP config

{
    "apps": {
        "user_ldap": {
            "enabled": "yes",
            "has_memberof_filter_support": "1",
            "home_folder_naming_rule": "",
            "last_jpegPhoto_lookup": "0",
            "ldap_agent_password": "***REMOVED SENSITIVE VALUE***",
            "ldap_attributes_for_group_search": "",
            "ldap_attributes_for_user_search": "cn\nsAMAccountName\nsurname\ngivenname\ncn\ndisplayname\nmail",
            "ldap_backup_host": "",
            "ldap_backup_port": "",
            "ldap_base": "DC=meins,DC=de",
            "ldap_base_groups": "CN=Users,DC=meins,DC=de",
            "ldap_base_users": "CN=Users,DC=meins,DC=de",
            "ldap_cache_ttl": "1",
            "ldap_configuration_active": "1",
            "ldap_dn": "CN=proxy_owncloud,CN=Proxy Users,DC=meins,DC=de",
            "ldap_dynamic_group_member_url": "",
            "ldap_email_attr": "mail",
            "ldap_experienced_admin": "0",
            "ldap_expert_uuid_group_attr": "sAMAccountName",
            "ldap_expert_uuid_user_attr": "sAMAccountName",
            "ldap_group_display_name": "cn",
            "ldap_group_filter_mode": "0",
            "ldap_group_member_assoc_attribute": "member",
            "ldap_groupfilter_groups": "",
            "ldap_groupfilter_objectclass": "group",
            "ldap_host": "srv.meins.de",
            "ldap_login_filter": "(sAMAccountName=%uid)",
            "ldap_loginfilter_attributes": "cn\nsAMAccountName\nuserPrincipalName\nmail",
            "ldap_loginfilter_email": "0",
            "ldap_loginfilter_username": "1",
            "ldap_nested_groups": "0",
            "ldap_override_main_server": "",
            "ldap_paging_size": "500",
            "ldap_port": "389",
            "ldap_quota_attr": "",
            "ldap_quota_def": "",
            "ldap_tls": "1",
            "ldap_turn_off_cert_check": "0",
            "ldap_user_display_name_2": "samaccountname",
            "ldap_userfilter_groups": "owncloudusers",
            "ldap_userfilter_objectclass": "user",
            "ldap_userlist_filter": "(objectClass=user)",
            "types": "authentication",
            "use_memberof_to_detect_membership": "1",
            "cleanUpJobOffset": "0",
            "installed_version": "1.1.2",
            "ldap_group_filter": "(&(|(objectclass=group)))",
            "ldap_display_name": "displayname",
            "ldap_expert_username_attr": "",
            "ldap_login_filter_mode": "1",
            "ldap_user_filter_mode": "0",
            "ldap_turn_on_pwd_change": "0"
        }
    }
}

Client configuration

Browser:

nextcloud client 2.3.1-20170504.063508

Operating system:

Ubuntu 16.04

Logs

Web server error log

Web server error log

Nothing error related found

Nextcloud log (data/nextcloud.log)

Nextcloud log

{"reqId":"tW9xLiwgwI00wZ94GqX9","remoteAddr":"2a01:XXXX","app":"webdav","message":"Exception: {\"Message\":\"An exception occurred while executing 'INSERT INTO \\\"oc_file_locks\\\" (\\\"key\\\",\\\"lock\\\",\\\"ttl\\\") SELECT ?,?,? FROM \\\"oc_file_locks\\\" WHERE \\\"key\\\" = ? HAVING COUNT(*) = 0' with params [\\\"files\\\\\\\/0348ac05d98fc6c42010315610dd35eb\\\", 1, 1494227358, \\\"files\\\\\\\/0348ac05d98fc6c42010315610dd35eb\\\"]:\\n\\nSQLSTATE[23505]: Unique violation: 7 ERROR:  duplicate key value violates unique constraint \\\"lock_key_index\\\"\\nDETAIL:  Key (key)=(files\\\/0348ac05d98fc6c42010315610dd35eb) already exists.\",\"Exception\":\"Doctrine\\\\DBAL\\\\Exception\\\\UniqueConstraintViolationException\",\"Code\":0,\"Trace\":\"#0 \\\/proj.stand\\\/web\\\/apps\\\/nextcloud\\\/instances\\\/prod\\\/nextcloud-11.0.3\\\/3rdparty\\\/doctrine\\\/dbal\\\/lib\\\/Doctrine\\\/DBAL\\\/DBALException.php(128): Doctrine\\\\DBAL\\\\Driver\\\\AbstractPostgreSQLDriver->convertException('An exception oc...', Object(Doctrine\\\\DBAL\\\\Driver\\\\PDOException))\\n#1 \\\/proj.stand\\\/web\\\/apps\\\/nextcloud\\\/instances\\\/prod\\\/nextcloud-11.0.3\\\/3rdparty\\\/doctrine\\\/dbal\\\/lib\\\/Doctrine\\\/DBAL\\\/Connection.php(996): Doctrine\\\\DBAL\\\\DBALException::driverExceptionDuringQuery(Object(Doctrine\\\\DBAL\\\\Driver\\\\PDOPgSql\\\\Driver), Object(Doctrine\\\\DBAL\\\\Driver\\\\PDOException), 'INSERT INTO \\\"oc...', Array)\\n#2 \\\/proj.stand\\\/web\\\/apps\\\/nextcloud\\\/instances\\\/prod\\\/nextcloud-11.0.3\\\/lib\\\/private\\\/DB\\\/Connection.php(215): Doctrine\\\\DBAL\\\\Connection->executeUpdate('INSERT INTO \\\"oc...', Array, Array)\\n#3 \\\/proj.stand\\\/web\\\/apps\\\/nextcloud\\\/instances\\\/prod\\\/nextcloud-11.0.3\\\/lib\\\/private\\\/DB\\\/Adapter.php(114): OC\\\\DB\\\\Connection->executeUpdate('INSERT INTO \\\"oc...', Array)\\n#4 \\\/proj.stand\\\/web\\\/apps\\\/nextcloud\\\/instances\\\/prod\\\/nextcloud-11.0.3\\\/lib\\\/private\\\/DB\\\/Connection.php(253): OC\\\\DB\\\\Adapter->insertIfNotExist('*PREFIX*file_lo...', Array, Array)\\n#5 \\\/proj.stand\\\/web\\\/apps\\\/nextcloud\\\/instances\\\/prod\\\/nextcloud-11.0.3\\\/lib\\\/private\\\/Lock\\\/DBLockingProvider.php(118): OC\\\\DB\\\\Connection->insertIfNotExist('*PREFIX*file_lo...', Array, Array)\\n#6 \\\/proj.stand\\\/web\\\/apps\\\/nextcloud\\\/instances\\\/prod\\\/nextcloud-11.0.3\\\/lib\\\/private\\\/Lock\\\/DBLockingProvider.php(163): OC\\\\Lock\\\\DBLockingProvider->initLockField('files\\\/0348ac05d...', 1)\\n#7 \\\/proj.stand\\\/web\\\/apps\\\/nextcloud\\\/instances\\\/prod\\\/nextcloud-11.0.3\\\/lib\\\/private\\\/Files\\\/Storage\\\/Common.php(680): OC\\\\Lock\\\\DBLockingProvider->acquireLock('files\\\/0348ac05d...', 1)\\n#8 \\\/proj.stand\\\/web\\\/apps\\\/nextcloud\\\/instances\\\/prod\\\/nextcloud-11.0.3\\\/lib\\\/private\\\/Files\\\/Storage\\\/Wrapper\\\/Wrapper.php(588): OC\\\\Files\\\\Storage\\\\Common->acquireLock('files\\\/photos\\\/20...', 1, Object(OC\\\\Lock\\\\DBLockingProvider))\\n#9 \\\/proj.stand\\\/web\\\/apps\\\/nextcloud\\\/instances\\\/prod\\\/nextcloud-11.0.3\\\/lib\\\/private\\\/Files\\\/Storage\\\/Wrapper\\\/Wrapper.php(588): OC\\\\Files\\\\Storage\\\\Wrapper\\\\Wrapper->acquireLock('files\\\/photos\\\/20...', 1, Object(OC\\\\Lock\\\\DBLockingProvider))\\n#10 \\\/proj.stand\\\/web\\\/apps\\\/nextcloud\\\/instances\\\/prod\\\/nextcloud-11.0.3\\\/lib\\\/private\\\/Files\\\/Storage\\\/Wrapper\\\/Wrapper.php(588): OC\\\\Files\\\\Storage\\\\Wrapper\\\\Wrapper->acquireLock('files\\\/photos\\\/20...', 1, Object(OC\\\\Lock\\\\DBLockingProvider))\\n#11 \\\/proj.stand\\\/web\\\/apps\\\/nextcloud\\\/instances\\\/prod\\\/nextcloud-11.0.3\\\/lib\\\/private\\\/Files\\\/View.php(1896): OC\\\\Files\\\\Storage\\\\Wrapper\\\\Wrapper->acquireLock('files\\\/photos\\\/20...', 1, Object(OC\\\\Lock\\\\DBLockingProvider))\\n#12 \\\/proj.stand\\\/web\\\/apps\\\/nextcloud\\\/instances\\\/prod\\\/nextcloud-11.0.3\\\/lib\\\/private\\\/Files\\\/View.php(2003): OC\\\\Files\\\\View->lockPath('\\\/photos\\\/2009-12...', 1)\\n#13 \\\/proj.stand\\\/web\\\/apps\\\/nextcloud\\\/instances\\\/prod\\\/nextcloud-11.0.3\\\/lib\\\/private\\\/Files\\\/View.php(1110): OC\\\\Files\\\\View->lockFile('\\\/photos\\\/2009-12...', 1)\\n#14 \\\/proj.stand\\\/web\\\/apps\\\/nextcloud\\\/instances\\\/prod\\\/nextcloud-11.0.3\\\/lib\\\/private\\\/Files\\\/View.php(967): OC\\\\Files\\\\View->basicOperation('fopen', '\\\/photos\\\/2009-12...', Array, 'rb')\\n#15 \\\/proj.stand\\\/web\\\/apps\\\/nextcloud\\\/instances\\\/prod\\\/nextcloud-11.0.3\\\/apps\\\/dav\\\/lib\\\/Connector\\\/Sabre\\\/File.php(305): OC\\\\Files\\\\View->fopen('photos\\\/2009-12-...', 'rb')\\n#16 \\\/proj.stand\\\/web\\\/apps\\\/nextcloud\\\/instances\\\/prod\\\/nextcloud-11.0.3\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/CorePlugin.php(85): OCA\\\\DAV\\\\Connector\\\\Sabre\\\\File->get()\\n#17 [internal function]: Sabre\\\\DAV\\\\CorePlugin->httpGet(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#18 \\\/proj.stand\\\/web\\\/apps\\\/nextcloud\\\/instances\\\/prod\\\/nextcloud-11.0.3\\\/3rdparty\\\/sabre\\\/event\\\/lib\\\/EventEmitterTrait.php(105): call_user_func_array(Array, Array)\\n#19 \\\/proj.stand\\\/web\\\/apps\\\/nextcloud\\\/instances\\\/prod\\\/nextcloud-11.0.3\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(479): Sabre\\\\Event\\\\EventEmitter->emit('method:GET', Array)\\n#20 \\\/proj.stand\\\/web\\\/apps\\\/nextcloud\\\/instances\\\/prod\\\/nextcloud-11.0.3\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(254): Sabre\\\\DAV\\\\Server->invokeMethod(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#21 \\\/proj.stand\\\/web\\\/apps\\\/nextcloud\\\/instances\\\/prod\\\/nextcloud-11.0.3\\\/apps\\\/dav\\\/lib\\\/Server.php(231): Sabre\\\\DAV\\\\Server->exec()\\n#22 \\\/proj.stand\\\/web\\\/apps\\\/nextcloud\\\/instances\\\/prod\\\/nextcloud-11.0.3\\\/apps\\\/dav\\\/appinfo\\\/v2\\\/remote.php(31): OCA\\\\DAV\\\\Server->exec()\\n#23 \\\/proj.stand\\\/web\\\/apps\\\/nextcloud\\\/instances\\\/prod\\\/nextcloud-11.0.3\\\/remote.php(165): require_once('\\\/proj.stand\\\/web...')\\n#24 {main}\",\"File\":\"\\\/proj.stand\\\/web\\\/apps\\\/nextcloud\\\/instances\\\/prod\\\/nextcloud-11.0.3\\\/3rdparty\\\/doctrine\\\/dbal\\\/lib\\\/Doctrine\\\/DBAL\\\/Driver\\\/AbstractPostgreSQLDriver.php\",\"Line\":63,\"User\":\"marcel\"}","level":4,"time":"2017-05-08T08:09:18+02:00","method":"GET","url":"\/nextcloud\/remote.php\/dav\/files\/marcel\/photos\/2009.jpg","user":"marcel","version":"11.0.3.2"}

Database log (postgresql.log)

Database postgres log

``` 2017-05-08 08:09:18 CEST [17838-1] nextcloud@nextcloud ERROR: 23505: duplicate key value violates unique constraint "lock_key_index" 2017-05-08 08:09:18 CEST [17838-2] nextcloud@nextcloud DETAIL: Key (key)=(files/0348ac05d98fc6c42010315610dd35eb) already exists. 2017-05-08 08:09:18 CEST [17838-3] nextcloud@nextcloud LOCATION: _bt_check_unique, nbtinsert.c:432 2017-05-08 08:09:18 CEST [17838-4] nextcloud@nextcloud STATEMENT: INSERT INTO "oc_file_locks" ("key","lock","ttl") SELECT $1,$2,$3 FROM "oc_file_locks" WHERE "key" = $4 HAVING COUNT(*) = 0

</details>

[LukasReschke]

@icewind1991

[linuxrrze]

Update:

• Trying to reproduce this behaviour in a clean docker environment - no luck so far.
• However while searching for differences in my installation and the docker test environment I observed connection losses between nextcloud client and the production machine. Digging into this I changed Apache setting "MaxKeepAliveRequests" to "0" (=unlimited) and then connection losses disappeared.
  (Setting this to higher values only increased the timeframe between sync errors, but did not fix the problem). This modification was not done in the docker image, where I couldn't observe any connection losses, so something else plays a role here: Hints welcome!

I'll run some more tests, but for now it looks like the database problems may be related to the unexpected connection losses.

[icewind1991]

As a workaround you can enable redis for file locking (which would also give much better performance).

See https://docs.nextcloud.com/server/11/admin_manual/configuration_files/files_locking_transactional.html