Core: duplicate key value violates unique constraint "oc_preferences_pkey" on every login

[spitzlei]

Steps to reproduce

1. Login to Owncloud Website
2. Open postgresql Serverlog
   

   Expected behaviour

No Error in logs

Actual behaviour

Logfile is being spammed with errors:
2016-03-14 09:48:10 GMT STATEMENT: INSERT INTO "oc_preferences" ("userid", "appid", "configkey", "configvalue") VALUES($1, $2, $3, $4)
2016-03-14 09:48:34 GMT ERROR: duplicate key value violates unique constraint "oc_preferences_pkey"
2016-03-14 09:48:34 GMT DETAIL: Key (userid, appid, configkey)=(testuser, files, quota) already exists.

(I already cleaned up the table, entries being set after next login. After logout und relogin Errors appear again).

Server configuration

Operating system:
Debian 8.3

Web server:
Package: apache2
Version: 2.4.10-10+deb8u1

Database:
Package: postgresql
Version: 9.4+165

PHP version:
Package: php5
Version: 5.6.17+dfsg-0+deb8u1

ownCloud version: (see ownCloud admin page)
9.0.0 (stable)

Updated from an older ownCloud or fresh install:
Update: 7 > 8 > 9

Where did you install ownCloud from:
deb http://download.owncloud.org/download/repositories/stable/Debian_8.0/ /

Signing status (ownCloud 9.0 and above):
No errors have been found.

List of activated apps:
Enabled:

• activity: 2.2.1
• calendar: 1.0
• comments: 0.2
• contacts: 1.0.0.0
• dav: 0.1.5
• external: 1.2
• federatedfilesharing: 0.1.0
• federation: 0.0.4
• files: 1.4.4
• files_external: 0.5.2
• files_pdfviewer: 0.8
• 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
• user_external
• user_ldap

The content of config/config.php:
{
"system": {
"instanceid": "_REMOVED_",
"passwordsalt": "_REMOVED SENSITIVE VALUE_",
"trusted_domains": [
"_REMOVED_"
],
"datadirectory": "\/var\/www\/owncloud\/data",
"dbtype": "pgsql",
"version": "9.0.0.19",
"dbname": "owncloud",
"dbhost": "localhost",
"dbtableprefix": "oc_",
"dbuser": "_REMOVED SENSITIVE VALUE_",
"dbpassword": "_REMOVED SENSITIVE VALUE_",
"installed": true,
"mail_from_address": "cloud",
"mail_smtpmode": "php",
"mail_domain": "_REMOVED_",
"forcessl": true,
"theme": "",
"maintenance": false,
"secret": "_REMOVED SENSITIVE VALUE_",
"loglevel": 2,
"memcache.local": "\OC\Memcache\APC",
"trashbin_retention_obligation": "auto",
"updatechecker": false
}
}

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:
no

Client configuration

Browser:
Firefox 45

Operating system:
Debian 8

[LukasReschke]

Duplicate of https://github.com/owncloud/core/issues/22563

[spitzlei]

Why is this a Duplicate?
I'm using Owncloud 9.0 and not 8.0 and here the oc_preferences tables is affected and not the oc_filecache.

[nebulade]

We are seeing a similar issue, maybe related but in LDAP code:

ERROR:  duplicate key value violates unique constraint "preferences_pkey"
Mar 14 19:38:07 smartserver.io docker[750]: 2016-03-14 19:38:07 UTC DETAIL:  Key (userid, appid, configkey)=(username, user_ldap, displayName) already exists.
Mar 14 19:38:07 smartserver.io docker[750]: 2016-03-14 19:38:07 UTC STATEMENT:  INSERT INTO "preferences" ("userid", "appid", "configkey", "configvalue") VALUES($1, $2, $3, $4)

If I understand #22563 correctly, can this be ignored for now? I am also using oC 9.0 but with mysql

[mobstef]

There is a workaround for this issue, which seems to affect ldap user login in 9.0.
To stop flooding of the logs with the reported error message add a rule to ignore the insert if the constraint violation would occur. After http://dba.stackexchange.com/questions/30499/optimal-way-to-ignore-duplicate-inserts:
CREATE OR REPLACE RULE oc_preferences_ignore_duplicate_inserts AS ON INSERT TO oc_preferences WHERE (EXISTS ( SELECT 1 FROM oc_preferences WHERE oc_preferences.userid = NEW.userid and oc_preferences.appid = NEW.appid and oc_preferences.configkey = NEW.configkey)) DO INSTEAD NOTHING;

[jknockaert]

Seeing a similar issue, but without LDAP:

[2016-03-22 16:23:33.169 CET] REMOVED ERROR:  duplicate key value violates unique constraint "oc_preferences_pkey"
[2016-03-22 16:23:33.169 CET] REMOVED DETAIL:  Key (userid, appid, configkey)=(REMOVED, login, lastLogin) already exists.
[2016-03-22 16:23:33.169 CET] REMOVED STATEMENT:  INSERT INTO "oc_preferences" ("userid", "appid", "configkey", "configvalue") VALUES($1, $2, $3, $4)

The postgres log is full of these lines. Especially with the os x client app this error happens multiple times per user per minute.

@LukasReschke Pls reopen. This happens on OC 9 (with postgres) and is not a duplicate of #22563

[jknockaert]

Do we already know which regression caused this behaviour?

[voidzero]

@mobstef Any idea how to reverse this query, for when the bug gets fixed?

[mobstef]

@voidzero Rather straightforward:
drop rule oc_preferences_ignore_duplicate_inserts on oc_preferences;

[voidzero]

Perfect, @mobstef. Much thanks.

[nickvergessen]

Just had a look at the code, it seems to be expected. We run the insert, then catch the php side exception that is thrown by doctrine when the key is violated and update instead.

Basically we could try and change the preference stuff to use insertIfNotExists(), but we can't do that in the current method Connection::setValues() because we don't know for all of the use-cases of the method, what keys they would need to check.

[jknockaert]

@nickvergessen What was changed in order to cause this behaviour? I have some server-side monitoring that triggers on multiple postgres errors. As a workaround I disabled the monitoring, but in my opinion these errors should not happen in the first place.

[nickvergessen]

Well the code was rewritten between oc7 and oc9, to be better suitable for consecutive actions. Before you could run into problems with parallel requests, because it did select if exists update otherwise insert. But if two requests do the select before the one of them does the insert/update you'd get an exception in php

[TDannhauer]

Hi, I have the same issue with Owncloud 9.0.4

[mgla]

I have the same issue with Owncloud 9.0.1-1.1

[israel-lugo]

Problem is still there on Owncloud 9.1.0-1.1 (Debian 8).

I realize it's convenient to deal with the exception at the PHP level, following the "ask for forgiveness" paradigm. However, this is causing real issues for some people at the SQL level. It is not nice to have postgresql-main.log full with thousands of error lines _every day_. The SNR is so low that it becomes very easy to miss a more important error.

Isn't there any other way to do this at the SQL level, without the race conditions? Perhaps some kind of INSERT INTO ... SELECT value1, value2, value3 WHERE NOT EXISTS (SELECT 1 FROM ... WHERE col1=value1). May not be the most obvious way to go about it, but it should work...

[rigrig]

We run the insert, then catch the php side exception that is thrown by doctrine when the key is violated and update instead.

I suppose you could first run update, then check the number of updated rows and if it is zero run the current code?

That seems messy though, I think running either select; {update or insert} or update; {if (rowCount == 0) then insert} inside a transaction would be better.

[mgla]

This bug forced us recently to change our postgres configuration considering connection limits and totla number of connection. Quite severe.

[Alphakilo]

@nickvergessen @rigrig
Postgres 9.5 has implemented the infamous UPSERT that does just that.

Reference:
https://wiki.postgresql.org/wiki/UPSERT
https://www.postgresql.org/docs/9.5/static/sql-insert.html

[TDannhauer]

Well, whats the status?

Any patch available? It is Sev2, so maybe we should come up with a solution. Bumping PostgreSQL dependency to >= 9.5 is not acceptable, isn't it?

[PVince81]

I suppose you could first run update, then check the number of updated rows and if it is zero run the current code?

This doesn't work if a concurrent process adds rows between these two operations, unless there is some kind of database level locking.

In many places ownCloud relies on expected ContraintViolationException to detect failed inserts. If this creates additional logs for Postgres then maybe we need a PostgreSQL specific solution that is also race-condition proof.

Currently, this logic is used in the following places:

lib/private/DB/Connection.php:          } catch (\Doctrine\DBAL\Exception\ConstraintViolationException $e) {
lib/private/Files/Config/UserMountCache.php:use Doctrine\DBAL\Exception\UniqueConstraintViolationException;
lib/private/Files/Type/Loader.php:use Doctrine\DBAL\Exception\UniqueConstraintViolationException;
lib/private/Files/Type/Loader.php:              } catch (UniqueConstraintViolationException $e) {
lib/private/SystemTag/SystemTagManager.php:use Doctrine\DBAL\Exception\UniqueConstraintViolationException;
lib/private/SystemTag/SystemTagManager.php:             } catch (UniqueConstraintViolationException $e) {
lib/private/SystemTag/SystemTagManager.php:             } catch (UniqueConstraintViolationException $e) {
lib/private/SystemTag/SystemTagObjectMapper.php:use Doctrine\DBAL\Exception\UniqueConstraintViolationException;
lib/private/SystemTag/SystemTagObjectMapper.php:                        } catch (UniqueConstraintViolationException $e) {

It might be possible to implement setValues inside of lib/private/DB/AdapterPgSql.php and then call the adapter from Connection::setValues here: https://github.com/owncloud/core/blob/v9.1.2/lib/private/DB/Connection.php#L271.

Here is an example how it was done with insertIfNotExists: https://github.com/owncloud/core/blob/v9.1.2/lib/private/DB/Connection.php#L247 and SQLite specific code https://github.com/owncloud/core/blob/v9.1.2/lib/private/DB/AdapterSqlite.php#L63

Anyone here up to the task ?

[rigrig]

I suppose you could first run update, then check the number of updated rows and if it is zero run the current code?

This doesn't work if a concurrent process adds rows between these two operations, unless there is some kind of database level locking.

I would work, either:
a) the rows already exist:
1) we update them and notice we updated >0 rows so are done
2) the concurrent process updates them as well
3) we don't do anything, because we were already done in 1)

b) the rows don't exist yet:
1) we run update and notice we updated 0 rows
2) the concurrent process inserts rows
3) we run the current code, which will throw and handle the exception as it does now

The advantage of this is that most of the time we are in situation a), so there will be a lot less errors logged.

But I think a proper solution would be to:
1) start a transaction
2) call update
3) if 0 rows were updated in 2): call insert
4) finish the transaction

[PVince81]

Would such transactions work for all DBs or should they be specific to PostgreSQL ?

@DeepDiver1975 @butonic I remember some discussions where transactions weren't possible, is this such a scenario ?

[jknockaert]

@@What about creating a custom function for this in the postgres database? I guess the setup of the database is already implementation-specific, so adding the function could be done there. Then the function should be called rather than insert, so that would be postgres-specific but it should be very manageable to abstract this.

[TDannhauer]

This specific function could even use upsert in Postgres 9.5+ to be as native as possible.

Von: Jasper Knockaert [mailto:[email protected]]
Gesendet: Montag, 21. November 2016 14:21
An: owncloud/core [email protected]
Cc: Torben Dannhauer [email protected]; Comment [email protected]
Betreff: Re: [owncloud/core] duplicate key value violates unique constraint "oc_preferences_pkey" on every login (#23213)

What about creating a custom function for this in the postgres database? I guess the setup of the database is already implementation-specific, so adding the function could be added there. Then the function should be called rather than insert, so that would be postgres-specific but it should be very manageable to abstract this.

—
You are receiving this because you commented.
Reply to this email directly, view it on GitHub https://github.com/owncloud/core/issues/23213#issuecomment-261936609 , or mute the thread https://github.com/notifications/unsubscribe-auth/AGZ6gUJgRv2oBFhZ5Ry5UU33T1D0tH-lks5rAZqjgaJpZM4Hv5tO . https://github.com/notifications/beacon/AGZ6gZsKcSULYchkG528Di7Vkgds2FBbks5rAZqjgaJpZM4Hv5tO.gif

[butonic]

While using db triggers would be nice (also to propagate etag changes and probably more) we first need to introduce doctrine based migrations ( help review the PR in https://github.com/owncloud/core/pull/14851 ) to get rid of the current automagic migration.

Then we can use explicit SQL up and downgrade scripts. And finally we can also convert the installation to be an SQL script that can use the dark magic of stored procedures ...

One step after another. Ideas and PRs / reviews welcome on what to move to stored procedures!

[jknockaert]

@butonic I guess the upsert functionality is an obvious one to move to stored procedures, right? Can you take this one up and make sure it lands in the proper place (and pls refer back to this one)? Then after that one is in, we can create a PR to solve this one.

[jknockaert]

This sev2 bug has been open for more than a year now. Any chance it will be fixed?

[PVince81]

@mrow4a can you have a look ?

[mrow4a]

EDIT: Ok, I reproduced your issue, indeed I found in the postgre log following entries. Will have a look at it now

---

This is how I tried to reproduce with upgrade 8.2->9.0, and problem exists:
psql (PostgreSQL) 9.5.6
Ubuntu
php7

1. Created user test1with quota 1GB
2. Created user test2 with unlimited quota
3. Logged in to both users, this populated oc_preferences table
4. Logged again to both users on 8.2 instance
5. 8.2->9.0 upgrade
6. Logged again to both users on 9.0 upgraded instance twice, everything works correctly.

[mrow4a]

I installed fresh ownCloud 9.0, problem exists

---

I installed fresh ownCloud 10, problem DOES not exist @PVince81 seems fixed in OC10, should I test upgrade from 9.1->10.0?

[mrow4a]

Seems fixed by @butonic around November https://github.com/owncloud/core/commit/9fe34ef9ef5ad4422660eaa7b7a435b2514e20ff for versions 9.1>

Hail @butonic, @PVince81 can we try to backport it to 9.0 and check if this fixes the issue?

[mrow4a]

@DeepDiver1975 Yet another motivation to get rid of <9.1 fantastic legacy code and doing query only with Doctrine and QueryBuilder, yet this is not strictly related to this issue?

[jknockaert]

No need for me to backport. If it is fixed then it is ok for me to just close this ticket.

[mrow4a]

Yep, but maybe I would need to check it again on Postgre if that really fixed the issue also for < 9.1 versions :>. Lets see what @butonic says, can I just cherry-pick https://github.com/owncloud/core/commit/9fe34ef9ef5ad4422660eaa7b7a435b2514e20ff and test again Posgre, wont it break sth?

[butonic]

Skimming this issue I only see a reference to an INSERT statement. The PR mentioned by @mrow4a only touches a SELECT. It does change the statement a little, however, as it adds a NOT NULL check: https://github.com/owncloud/core/commit/9fe34ef9ef5ad4422660eaa7b7a435b2514e20ff#diff-512d39632663dc8e28bba3e11ac5dd52R423

@mrow4a If you can reproduce this I'd like to verify the PR actually fixes this issue as it was intended to fix an oracle only problem. Could you backport?

[mrow4a]

@jknockaert @butonic @PVince81 I verified and on OC9.1 the issue exists, and on OC10 issue is solved, because setUserValue function is not being called on repetitive login (called only on first user login) and also different values are being inserted to oc_preferences table. I also upgraded from 9.1->10. However, we cannot backport it to lower version, because code responsible for that has been completely refactored for version 10 and it is not related (directly) to the COMMIT I mentioned above, as I was hoping it will be.

Is it ok for you that it is solved in 10 and I can close the ticket? Please reopen if it happens again in OC10

[mrow4a]

@DeepDiver1975 Now oc_accounts table is responsible for these things right, I think it was your crazy long PR https://github.com/owncloud/core/pull/27276/files#diff-37958be4e01e8baeb127a59409e1a593R125? Sorry @butonic, it was Thomas hard work i think, not yours .. :>

[mrow4a]

Debugging further the issue to find corner cases, one could experience "one-time" violation if he is changing the language e.g. from English to Polish etc, so next login after the change will once experience it, however any consequtive login wont. @DeepDiver1975 any priority on fixing this, since it is only happening once user changes his preference? (It is not violating during initialization of the preference and not with consequtive logins)

[mrow4a]

I could not stand looking at this "universal querying" and there is ongoing PR https://github.com/owncloud/core/pull/27576, which will fix above issue in OC10 and potentialy all other if backported to <9.1 (needs checking the backport). However ideally we should kill that setValue thing, I am not a fan of "universality" in big scale instances, but this i not in scope of OC10 I guess ( @DeepDiver1975 ?)

[PVince81]

once user changes his preference

There is more code that changes stuff in oc_preferences than just changing the language I think.
Third party apps are also able to store user preferences there, so I suspect the exception might be logged for those cases as well.

[israel-lugo]

@mrow4a Please note that the message does appear after consecutive logins, at least in my use case. I am not changing languages every day, yet I had 142 occurrences of the message in the last 12 hours. Just normal contact/calendar sync traffic from my clients (cellphone, MUA).

[mrow4a]

Yep, will wake up the topic in here https://github.com/owncloud/core/pull/27576, I already fixed it, however needs some adjustment.

[lock[bot]]

This thread has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.